Skip to content

Instantly share code, notes, and snippets.

@phildunks
Created July 2, 2019 13:54
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save phildunks/035dafadebd3ec52c1baf58b92d21cc1 to your computer and use it in GitHub Desktop.
Save phildunks/035dafadebd3ec52c1baf58b92d21cc1 to your computer and use it in GitHub Desktop.
Race condition logs.
drachtio:srf examining INVITE, dialog id: +4m
Received an Invite from 172.17.0.1:36128
Handling Media Leg Invite
drachtio:srf createB2BUA: creating UAC, opts: {"localSdp":"v=0\r\no=FreeSWITCH 1562059779 1562059780 IN IP4 192.168.47.26\r\ns=FreeSWITCH\r\nc=IN IP4 192.168.47.26\r\nt=0 0\r\nm=audio 15486 RTP/AVP 0 98 99 9 8 3 101 13\r\na=rtpmap:98 G7221/32000\r\na=fmtp:98 bitrate=48000\r\na=rtpmap:99 G7221/16000\r\na=fmtp:99 bitrate=32000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-16\r\na=ptime:20\r\n","uri":"sip:1234@192.168.47.134:5060","method":"INVITE","headers":{},"responseHeaders":{},"callingNumber":"mm2dev-slee","calledNumber":"msml"} +1ms
drachtio:srf Srf#addDialog: adding dialog with id d04e7e68-1772-1238-33bc-0242ac110002;from-tag=6m4rQ41acge1g type INVITE, dialog count is now 1 +51ms
drachtio:srf createB2BUA: successfully created UAC.. +0ms
drachtio:srf copyUACHeadersToUAS: {} +0ms
drachtio:srf createB2BUA: generateSdpA +0ms
drachtio:srf Srf#addDialog: adding dialog with id st5hsVxKUj;from-tag=1213582815620752658891.0 type INVITE, dialog count is now 2 +24ms
drachtio:srf examining ACK, dialog id: st5hsVxKUj;from-tag=1213582815620752658891.0 +2ms
drachtio:srf calling dialog handler +0ms
drachtio:srf Dialog handling message: ACK +4m
drachtio:srf examining INFO, dialog id: st5hsVxKUj;from-tag=1213582815620752658891.0 +1ms
drachtio:srf calling dialog handler +0ms
drachtio:srf Dialog handling message: INFO +1ms
drachtio:srf createB2BUA: successfully created UAS..done! +1ms
Created B2BUA
Added Tag to Store [7XXHSZje9r4Kc] [d04e7e68-1772-1238-33bc-0242ac110002]. Store Size = 2
drachtio:srf examining BYE, dialog id: st5hsVxKUj;from-tag=1213582815620752658891.0 +51ms
drachtio:srf calling dialog handler +0ms
drachtio:srf Dialog handling message: BYE +52ms
drachtio:srf Srf#removeDialog: removing dialog with id st5hsVxKUj;from-tag=1213582815620752658891.0 dialog count is now 1 +0ms
MM2 Ended Call
Removed Tag from Store [7XXHSZje9r4Kc] [d04e7e68-1772-1238-33bc-0242ac110002]. Store Size = 0
Leg Hung Up - nothing to do.
drachtio:srf Srf#removeDialog: removing dialog with id d04e7e68-1772-1238-33bc-0242ac110002;from-tag=6m4rQ41acge1g dialog count is now 0 +7ms
2019-07-02 13:47:46.004858 tport.c:2777 tport_wakeup_pri() tport_wakeup_pri(0x55d2415275a0): events IN
2019-07-02 13:47:46.005050 tport.c:2892 tport_recv_event() tport_recv_event(0x55d2415275a0)
2019-07-02 13:47:46.005170 tport.c:3233 tport_recv_iovec() tport_recv_iovec(0x55d2415275a0) msg 0x55d2415cf500 from (udp/172.17.0.2:5060) has 724 bytes, veclen = 1
2019-07-02 13:47:46.005484 recv 724 bytes from udp/[172.17.0.1]:36128 at 13:47:46.005264:
INVITE sip:msml@192.168.47.161:5060 SIP/2.0
Max-Forwards: 70
Content-Length: 315
Contact: <sip:mm2dev-slee@192.168.46.213:5062;transport=UDP>
To: <sip:msml@192.168.47.161:5060>
CSeq: 1 INVITE
Via: SIP/2.0/UDP 192.168.46.213:5062;branch=z9hG4bKnuxt05PZd8VVqfliW60p51
Call-ID: st5hsVxKUj
Content-Type: application/sdp
From: "mm2dev-slee"<sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0
v=0
o=FreeSWITCH 1562059779 1562059780 IN IP4 192.168.47.26
s=FreeSWITCH
c=IN IP4 192.168.47.26
t=0 0
m=audio 15486 RTP/AVP 0 98 99 9 8 3 101 13
a=rtpmap:98 G7221/32000
a=fmtp:98 bitrate=48000
a=rtpmap:99 G7221/16000
a=fmtp:99 bitrate=32000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
2019-07-02 13:47:46.005555 tport.c:3051 tport_deliver() tport_deliver(0x55d2415275a0): msg 0x55d2415cf500 (724 bytes) from udp/172.17.0.1:5060 next=(nil)
2019-07-02 13:47:46.005602 nta.c:3028 agent_recv_request() nta: received INVITE sip:msml@192.168.47.161:5060 SIP/2.0 (CSeq 1)
2019-07-02 13:47:46.005651 nta.c:3323 agent_check_request_via() nta: Via check: received=172.17.0.1
2019-07-02 13:47:46.005692 nta.c:3397 agent_aliases() nta: canonizing sip:msml@192.168.47.161:5060 with contact
2019-07-02 13:47:46.005746 nta.c:3243 agent_recv_request() nta: INVITE (1) to message callback
2019-07-02 13:47:46.005789 processMessageStatelessly - incoming message with call-id st5hsVxKUj does not match an existing call leg, processed in thread 140714029569856
2019-07-02 13:47:46.005879 tport.c:3285 tport_tsend() tport_tsend(0x55d2415275a0) tpn = UDP/172.17.0.1:36128
2019-07-02 13:47:46.005923 tport.c:4085 tport_resolve() tport_resolve addrinfo = 172.17.0.1:36128
2019-07-02 13:47:46.006052 tport.c:3531 tport_send_msg() tport_vsend returned 304
2019-07-02 13:47:46.006157 send 304 bytes to udp/[172.17.0.1]:36128 at 13:47:46.005965:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.46.213:5062;branch=z9hG4bKnuxt05PZd8VVqfliW60p51;received=172.17.0.1;rport=36128
From: "mm2dev-slee" <sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0
To: <sip:msml@192.168.47.161:5060>
Call-ID: st5hsVxKUj
CSeq: 1 INVITE
Content-Length: 0
2019-07-02 13:47:46.006208 ClientController::selectClientForRequestOutsideDialog - there are 1 possible clients, we are starting with offset 0
2019-07-02 13:47:46.006257 ClientController::route_request_outside_dialog - Selected client at offset 0
2019-07-02 13:47:46.006319 PendingRequestController::add - tport: 0x55d2415275a0, Call-ID: st5hsVxKUj, transactionId 64680ee7-2d5f-4940-9f3c-637108da7ef0
2019-07-02 13:47:46.006372 pending-request: Adding entry to go off in 64000ms
2019-07-02 13:47:46.006413 pending-request: Adding entry to the head (queue was empty), length: 1
2019-07-02 13:47:46.006514 ClientController::addNetTransaction: transactionId 64680ee7-2d5f-4940-9f3c-637108da7ef0; size: 3
2019-07-02 13:47:46.006671 Client::write_handler - wrote 889 bytes: system:0
2019-07-02 13:47:46.006730 No connected clients found to handle incoming cdr:attempt request
2019-07-02 13:47:46.010895 Client::read_handler read: b785cfae-e9db-4e1b-ad7c-c71774808d62|sip||
INVITE sip:1234@192.168.47.134:5060 SIP/2.0
from: sip:mm2dev-slee@localhost
contact: sip:mm2dev-slee@localhost
Content-Length: 315
v=0
o=FreeSWITCH 1562059779 1562059780 IN IP4 192.168.47.26
s=FreeSWITCH
c=IN IP4 192.168.47.26
t=0 0
m=audio 15486 RTP/AVP 0 98 99 9 8 3 101 13
a=rtpmap:98 G7221/32000
a=fmtp:98 bitrate=48000
a=rtpmap:99 G7221/16000
a=fmtp:99 bitrate=32000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
2019-07-02 13:47:46.011026 Client::processMessage - got request with 4 tokens
2019-07-02 13:47:46.011070 Client::processMessage - request id b785cfae-e9db-4e1b-ad7c-c71774808d62, request type: sip transaction id: , dialog id:
2019-07-02 13:47:46.011168 Client::processMessage - sending a request outside of a dialog
2019-07-02 13:47:46.011250 ClientController::addAppTransaction: transactionId 58bc9f6e-e355-4196-befd-7ee3429ba9b0; size: 1
2019-07-02 13:47:46.011297 ClientController::addApiRequest: clientMsgId b785cfae-e9db-4e1b-ad7c-c71774808d62; size: 1
2019-07-02 13:47:46.011405 DrachtioController::findTportForSubscription: no transport found for 1234@192.168.47.134
2019-07-02 13:47:46.013733 SipTransport::findAppropriateTransport: searching for a transport to reach udp/sip:1234@192.168.47.134:5060
2019-07-02 13:47:46.013846 SipTransport::findAppropriateTransport - after filtering for transport we have 4 candidates
2019-07-02 13:47:46.013893 SipTransport::findAppropriateTransport - after filtering for protocol we have 2 candidates
2019-07-02 13:47:46.015799 SipTransport::findAppropriateTransport: - returning the best match 0x55d2415275a0: udp/172.17.0.2:5060
2019-07-02 13:47:46.015897 SipTransport::getContactUri - created Contact header: sip:192.168.47.161:5060
2019-07-02 13:47:46.015936 SipDialogController::doSendRequestOutsideDialog selected transport 0x55d2415275a0udp/172.17.0.2:5060
2019-07-02 13:47:46.016220 makeTags - using external IP as replacement for 'localhost': 192.168.47.161
2019-07-02 13:47:46.016308 makeTags - hdr 'from' replacing host with 192.168.47.161
2019-07-02 13:47:46.016354 makeTags - Adding well-known header 'from' with value '<sip:mm2dev-slee@192.168.47.161:5060>'
2019-07-02 13:47:46.016435 makeTags - hdr 'contact' replacing host with 192.168.47.161
2019-07-02 13:47:46.016478 makeTags - Adding well-known header 'contact' with value '<sip:mm2dev-slee@192.168.47.161:5060>'
2019-07-02 13:47:46.016521 SipDialogController::doSendRequestOutsideDialog - from: <sip:mm2dev-slee@192.168.47.161:5060>
2019-07-02 13:47:46.016615 SipDialogController::doSendRequestOutsideDialog - to: sip:1234@192.168.47.134:5060
2019-07-02 13:47:46.016663 SipDialogController::doSendRequestOutsideDialog - contact: <sip:192.168.47.161:5060>
2019-07-02 13:47:46.016699 SipDialogController::doSendRequestOutsideDialog - automatically detecting content-type as application/sdp
2019-07-02 13:47:46.016772 isLocalSipUri: checking to see if this is one of mine: sip:1234@192.168.47.134:5060
2019-07-02 13:47:46.016852 nta.c:4566 nta_leg_tcreate() nta_leg_tcreate(0x55d24158a630)
2019-07-02 13:47:46.016926 nta.c:2813 nta_tpn_by_url() nta: selecting scheme sip
2019-07-02 13:47:46.017018 tport.c:3285 tport_tsend() tport_tsend(0x55d2415275a0) tpn = */192.168.47.134:5060
2019-07-02 13:47:46.017091 tport.c:4085 tport_resolve() tport_resolve addrinfo = 192.168.47.134:5060
2019-07-02 13:47:46.017228 tport.c:3531 tport_send_msg() tport_vsend returned 715
2019-07-02 13:47:46.017459 send 715 bytes to udp/[192.168.47.134]:5060 at 13:47:46.017136:
INVITE sip:1234@192.168.47.134:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.47.161;rport;branch=z9hG4bKt8cDFXX3eg88e
Max-Forwards: 70
From: <sip:mm2dev-slee@192.168.47.161:5060>;tag=6m4rQ41acge1g
To: <sip:1234@192.168.47.134:5060>
Call-ID: d04e7e68-1772-1238-33bc-0242ac110002
CSeq: 6483841 INVITE
Contact: <sip:mm2dev-slee@192.168.47.161:5060>
Content-Type: application/sdp
Content-Length: 315
v=0
o=FreeSWITCH 1562059779 1562059780 IN IP4 192.168.47.26
s=FreeSWITCH
c=IN IP4 192.168.47.26
t=0 0
m=audio 15486 RTP/AVP 0 98 99 9 8 3 101 13
a=rtpmap:98 G7221/32000
a=fmtp:98 bitrate=48000
a=rtpmap:99 G7221/16000
a=fmtp:99 bitrate=32000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
2019-07-02 13:47:46.017621 nta.c:8470 outgoing_send() nta: sent INVITE (6483841) to */192.168.47.134:5060
2019-07-02 13:47:46.017688 tport.c:4199 tport_pend() tport_pend(0x55d2415275a0): pending 0x55d2415ba270 for udp/172.17.0.2:5060 (already 0)
2019-07-02 13:47:46.017789 nta.c:1411 set_timeout() nta: timer set to 32000 ms
2019-07-02 13:47:46.017901 nta.c:1409 set_timeout() nta: timer shortened to 1000 ms
2019-07-02 13:47:46.017960 SipDialog::SipDialog - creating dialog for outbound INVITE sent from udp/172.17.0.2:5060 to 192.168.47.134:5060
2019-07-02 13:47:46.017998 SipDialogController::addOutgoingInviteTransaction: adding leg 0x55d24158a630
2019-07-02 13:47:46.018094 No connected clients found to handle incoming cdr:attempt request
2019-07-02 13:47:46.018184 ClientController::removeApiRequest: clientMsgId b785cfae-e9db-4e1b-ad7c-c71774808d62; size: 0
2019-07-02 13:47:46.021941 Client::write_handler - wrote 906 bytes: system:0
2019-07-02 13:47:46.022099 tport.c:2777 tport_wakeup_pri() tport_wakeup_pri(0x55d2415275a0): events IN
2019-07-02 13:47:46.022166 tport.c:2892 tport_recv_event() tport_recv_event(0x55d2415275a0)
2019-07-02 13:47:46.022245 tport.c:3233 tport_recv_iovec() tport_recv_iovec(0x55d2415275a0) msg 0x55d2415bf650 from (udp/172.17.0.2:5060) has 360 bytes, veclen = 1
2019-07-02 13:47:46.022407 recv 360 bytes from udp/[192.168.47.134]:5060 at 13:47:46.022295:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.47.161;rport=60574;branch=z9hG4bKt8cDFXX3eg88e
From: <sip:mm2dev-slee@192.168.47.161:5060>;tag=6m4rQ41acge1g
To: <sip:1234@192.168.47.134:5060>
Call-ID: d04e7e68-1772-1238-33bc-0242ac110002
CSeq: 6483841 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20190606T174518Z~813a37d844~64bit
Content-Length: 0
2019-07-02 13:47:46.022484 tport.c:3051 tport_deliver() tport_deliver(0x55d2415275a0): msg 0x55d2415bf650 (360 bytes) from udp/192.168.47.134:5060 next=(nil)
2019-07-02 13:47:46.022537 nta.c:3448 agent_recv_response() nta: received 100 Trying for INVITE (6483841)
2019-07-02 13:47:46.022645 nta.c:3515 agent_recv_response() nta: 100 Trying is going to a transaction
2019-07-02 13:47:46.022699 nta.c:9734 outgoing_estimate_delay() nta_outgoing: RTT is 5.678 ms
2019-07-02 13:47:46.022753 tport.c:4261 tport_release() tport_release(0x55d2415275a0): 0x55d2415ba270 by 0x55d2415cd270 with 0x55d2415bf650 (preliminary)
2019-07-02 13:47:46.030390 tport.c:2777 tport_wakeup_pri() tport_wakeup_pri(0x55d2415275a0): events IN
2019-07-02 13:47:46.030564 tport.c:2892 tport_recv_event() tport_recv_event(0x55d2415275a0)
2019-07-02 13:47:46.030674 tport.c:3233 tport_recv_iovec() tport_recv_iovec(0x55d2415275a0) msg 0x55d2415bb380 from (udp/172.17.0.2:5060) has 1048 bytes, veclen = 1
2019-07-02 13:47:46.031100 recv 1048 bytes from udp/[192.168.47.134]:5060 at 13:47:46.030764:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.47.161;rport=60574;branch=z9hG4bKt8cDFXX3eg88e
From: <sip:mm2dev-slee@192.168.47.161:5060>;tag=6m4rQ41acge1g
To: <sip:1234@192.168.47.134:5060>;tag=Bjtj22yXe9F6Q
Call-ID: d04e7e68-1772-1238-33bc-0242ac110002
CSeq: 6483841 INVITE
Contact: <sip:1234@192.168.47.134:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20190606T174518Z~813a37d844~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Session-Expires: 1800;refresher=uas
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 248
Remote-Party-ID: "1234" <sip:1234@192.168.47.134>;party=calling;privacy=off;screen=no
v=0
o=FreeSWITCH 1562040803 1562040804 IN IP4 192.168.47.134
s=FreeSWITCH
c=IN IP4 192.168.47.134
t=0 0
m=audio 34462 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
2019-07-02 13:47:46.031166 tport.c:3051 tport_deliver() tport_deliver(0x55d2415275a0): msg 0x55d2415bb380 (1048 bytes) from udp/192.168.47.134:5060 next=(nil)
2019-07-02 13:47:46.031246 nta.c:3448 agent_recv_response() nta: received 200 OK for INVITE (6483841)
2019-07-02 13:47:46.031331 nta.c:3515 agent_recv_response() nta: 200 OK is going to a transaction
2019-07-02 13:47:46.031386 tport.c:4261 tport_release() tport_release(0x55d2415275a0): 0x55d2415ba270 by 0x55d2415cd270 with 0x55d2415bb380
2019-07-02 13:47:46.031448 SipDialogController::processResponseOutsideDialog
2019-07-02 13:47:46.031512 SipDialogController::processResponse - adding dialog id: d04e7e68-1772-1238-33bc-0242ac110002;from-tag=6m4rQ41acge1g
2019-07-02 13:47:46.031639 ClientController::addDialogForTransaction - added dialog (uac), now tracking: 11 dialogs and 1 app transactions
2019-07-02 13:47:46.031714 ClientController::addDialogForTransaction - transaction id 58bc9f6e-e355-4196-befd-7ee3429ba9b0 has associated dialog d04e7e68-1772-1238-33bc-0242ac110002;from-tag=6m4rQ41acge1g
2019-07-02 13:47:46.031857 timerD: Adding entry to go off in 32500ms
2019-07-02 13:47:46.031916 timerD: Adding entry to the head (queue was empty), length: 1
2019-07-02 13:47:46.032017 TimerDHandler::addInvite 0x55d2415cd270, d04e7e68-1772-1238-33bc-0242ac1100026483841
2019-07-02 13:47:46.032211 Client::write_handler - wrote 1246 bytes: system:0
2019-07-02 13:47:46.032290 ClientController::removeAppTransaction: transactionId 58bc9f6e-e355-4196-befd-7ee3429ba9b0; size: 0
2019-07-02 13:47:46.032368 No connected clients found to handle incoming cdr:start request
2019-07-02 13:47:46.061960 Client::read_handler read: 60a20a02-a887-47cd-ae3f-1dd67462c026|sip||d04e7e68-1772-1238-33bc-0242ac110002;from-tag=6m4rQ41acge1g
ACK sip:1234@192.168.47.134:5060 SIP/2.0
Content-Length: 0
2019-07-02 13:47:46.062108 Client::processMessage - got request with 4 tokens
2019-07-02 13:47:46.062169 Client::processMessage - request id 60a20a02-a887-47cd-ae3f-1dd67462c026, request type: sip transaction id: , dialog id: d04e7e68-1772-1238-33bc-0242ac110002;from-tag=6m4rQ41acge1g
2019-07-02 13:47:46.062229 Client::processMessage - sending a request inside a dialog (dialogId provided)
2019-07-02 13:47:46.062311 ClientController::addApiRequest: clientMsgId 60a20a02-a887-47cd-ae3f-1dd67462c026; size: 1
2019-07-02 13:47:46.062556 SipDialogController::doSendRequestInsideDialog dialog id: d04e7e68-1772-1238-33bc-0242ac110002;from-tag=6m4rQ41acge1g
2019-07-02 13:47:46.062556 Client::read_handler read: 06d0c7f8-9a85-41f6-a68d-3fb27a7c9bc0|sip|64680ee7-2d5f-4940-9f3c-637108da7ef0|
SIP/2.0 200 OK
Call-ID: st5hsVxKUj
cseq: 1 INVITE
from: "mm2dev-slee"<sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0
to: <sip:msml@192.168.47.161:5060>
Content-Length: 248
v=0
o=FreeSWITCH 1562040803 1562040804 IN IP4 192.168.47.134
s=FreeSWITCH
c=IN IP4 192.168.47.134
t=0 0
m=audio 34462 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
2019-07-02 13:47:46.062815 Client::processMessage - got request with 4 tokens
2019-07-02 13:47:46.062875 Client::processMessage - request id 06d0c7f8-9a85-41f6-a68d-3fb27a7c9bc0, request type: sip transaction id: 64680ee7-2d5f-4940-9f3c-637108da7ef0, dialog id:
2019-07-02 13:47:46.062937 ClientController::addApiRequest: clientMsgId 06d0c7f8-9a85-41f6-a68d-3fb27a7c9bc0; size: 2
2019-07-02 13:47:46.063134 SipDialogController::doSendRequestInsideDialog - defaulting request uri to sip:1234@192.168.47.134:5060;transport=udp
2019-07-02 13:47:46.063215 DrachtioController::findTportForSubscription: no transport found for 1234@192.168.47.134
2019-07-02 13:47:46.063334 nta.c:2813 nta_tpn_by_url() nta: selecting scheme sip
2019-07-02 13:47:46.063416 tport.c:3285 tport_tsend() tport_tsend(0x55d2415275a0) tpn = udp/192.168.47.134:5060
2019-07-02 13:47:46.063476 tport.c:4085 tport_resolve() tport_resolve addrinfo = 192.168.47.134:5060
2019-07-02 13:47:46.063646 tport.c:3531 tport_send_msg() tport_vsend returned 345
2019-07-02 13:47:46.063836 send 345 bytes to udp/[192.168.47.134]:5060 at 13:47:46.063534:
ACK sip:1234@192.168.47.134:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.47.161;rport;branch=z9hG4bKUH65gre7BSyUa
Max-Forwards: 70
From: <sip:mm2dev-slee@192.168.47.161:5060>;tag=6m4rQ41acge1g
To: <sip:1234@192.168.47.134:5060>;tag=Bjtj22yXe9F6Q
Call-ID: d04e7e68-1772-1238-33bc-0242ac110002
CSeq: 6483841 ACK
Content-Length: 0
2019-07-02 13:47:46.063902 nta.c:8470 outgoing_send() nta: sent ACK (6483841) to udp/192.168.47.134:5060
2019-07-02 13:47:46.063975 TimerDHandler::addAck 0x55d2415b6e60, d04e7e68-1772-1238-33bc-0242ac1100026483841
2019-07-02 13:47:46.064029 SipDialogController::doSendRequestInsideDialog - clearing IIP that we generated as uac
2019-07-02 13:47:46.064085 SipDialogController::clearIIP: clearing leg 0x55d24158a630, irq: 0, orq: 0x55d2415cd270, rel: 0
2019-07-02 13:47:46.064162 SipDialogController::clearIIP: clearing m_mapOrq2IIP for leg 0x55d24158a630
2019-07-02 13:47:46.064280 ClientController::removeApiRequest: clientMsgId 60a20a02-a887-47cd-ae3f-1dd67462c026; size: 1
2019-07-02 13:47:46.064424 SipDialogController::doRespondToSipRequest thread 140714029569856
2019-07-02 13:47:46.064503 SipDialogController::findAndRemoveTransactionIdForIncomingRequest - searching transactionId 64680ee7-2d5f-4940-9f3c-637108da7ef0
2019-07-02 13:47:46.064572 SipDialogController::findAndRemoveTransactionIdForIncomingRequest - failed to find transactionId 64680ee7-2d5f-4940-9f3c-637108da7ef0, most likely this is a response to an invite we sent
2019-07-02 13:47:46.064654 Client::write_handler - wrote 536 bytes: system:0
2019-07-02 13:47:46.064677 pending-request: removing entry, prior to removal length: 1
2019-07-02 13:47:46.064726 pending-request: removed entry, timer not set (queue is empty after removal), length: 0
2019-07-02 13:47:46.064843 nta.c:1409 set_timeout() nta: timer shortened to 200 ms
2019-07-02 13:47:46.064942 nta.c:4566 nta_leg_tcreate() nta_leg_tcreate(0x55d2415b7550)
2019-07-02 13:47:46.065017 DrachtioController::setupLegForIncomingRequest - created leg: 0x55d2415b7550, irq: 0x55d2415c73d0, for transactionId: 64680ee7-2d5f-4940-9f3c-637108da7ef0
2019-07-02 13:47:46.065102 SipDialog::SipDialog - (UAS) detected client behind nat, using 172.17.0.1:36128 as route for requests within this dialog
2019-07-02 13:47:46.065195 SipDialog::SipDialog - creating dialog for inbound INVITE sent from UDP/172.17.0.2:5060
2019-07-02 13:47:46.065292 SipDialogController::addIncomingInviteTransaction: added iip: 0x55d2415c7520 with leg 0x55d2415b7550, irq: 0x55d2415c73d0, transactionId 64680ee7-2d5f-4940-9f3c-637108da7ef0, iip size: 1
2019-07-02 13:47:46.065356 SipDialogController::doRespondToSipRequest found invite or subscribe in progress 0x55d2415c7520
2019-07-02 13:47:46.065444 SipTransport::getContactUri - created Contact header: sip:192.168.47.161:5060
2019-07-02 13:47:46.066040 makeTags - Adding well-known header 'Call-ID' with value 'st5hsVxKUj'
2019-07-02 13:47:46.066136 makeTags - Adding well-known header 'cseq' with value '1 INVITE'
2019-07-02 13:47:46.066224 makeTags - Adding well-known header 'from' with value '"mm2dev-slee"<sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0'
2019-07-02 13:47:46.066276 makeTags - Adding well-known header 'to' with value '<sip:msml@192.168.47.161:5060>'
2019-07-02 13:47:46.066372 Sending 200 response (not reliably) on irq 0x55d2415c73d0
2019-07-02 13:47:46.066567 tport.c:3285 tport_tsend() tport_tsend(0x55d2415275a0) tpn = UDP/172.17.0.1:36128
2019-07-02 13:47:46.066608 tport.c:4085 tport_resolve() tport_resolve addrinfo = 172.17.0.1:36128
2019-07-02 13:47:46.066787 tport.c:3531 tport_send_msg() tport_vsend returned 635
2019-07-02 13:47:46.066948 send 635 bytes to udp/[172.17.0.1]:36128 at 13:47:46.066688:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.46.213:5062;branch=z9hG4bKnuxt05PZd8VVqfliW60p51;received=172.17.0.1;rport=36128
From: "mm2dev-slee" <sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0
To: <sip:msml@192.168.47.161:5060>;tag=7XXHSZje9r4Kc
Call-ID: st5hsVxKUj
CSeq: 1 INVITE
Contact: <sip:192.168.47.161:5060>
Content-Type: application/sdp
Content-Length: 248
v=0
o=FreeSWITCH 1562040803 1562040804 IN IP4 192.168.47.134
s=FreeSWITCH
c=IN IP4 192.168.47.134
t=0 0
m=audio 34462 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
2019-07-02 13:47:46.066995 nta.c:6939 incoming_reply() nta: sent 200 OK for INVITE (1)
2019-07-02 13:47:46.067098 ClientController::addDialogForTransaction - added dialog (uas), now tracking: 12 dialogs and 3 net transactions
2019-07-02 13:47:46.067176 ClientController::addDialogForTransaction - transaction id 64680ee7-2d5f-4940-9f3c-637108da7ef0 has associated dialog st5hsVxKUj;from-tag=1213582815620752658891.0
2019-07-02 13:47:46.067263 timerG: Adding entry to go off in 500ms
2019-07-02 13:47:46.067325 timerG: Adding entry to the head (queue was empty), length: 1
2019-07-02 13:47:46.067381 timerH: Adding entry to go off in 32000ms
2019-07-02 13:47:46.067417 timerH: Adding entry to the head (queue was empty), length: 1
2019-07-02 13:47:46.067458 ClientController::removeApiRequest: clientMsgId 06d0c7f8-9a85-41f6-a68d-3fb27a7c9bc0; size: 0
2019-07-02 13:47:46.067573 No connected clients found to handle incoming cdr:start request
2019-07-02 13:47:46.067765 Client::write_handler - wrote 873 bytes: system:0
2019-07-02 13:47:46.080774 tport.c:2777 tport_wakeup_pri() tport_wakeup_pri(0x55d2415275a0): events IN
2019-07-02 13:47:46.080926 tport.c:2892 tport_recv_event() tport_recv_event(0x55d2415275a0)
2019-07-02 13:47:46.080983 tport.c:3233 tport_recv_iovec() tport_recv_iovec(0x55d2415275a0) msg 0x55d2415b91f0 from (udp/172.17.0.2:5060) has 321 bytes, veclen = 1
2019-07-02 13:47:46.081151 recv 321 bytes from udp/[172.17.0.1]:36128 at 13:47:46.081035:
ACK sip:192.168.47.161:5060 SIP/2.0
Max-Forwards: 70
Content-Length: 0
To: <sip:msml@192.168.47.161:5060>;tag=7XXHSZje9r4Kc
CSeq: 1 ACK
Via: SIP/2.0/UDP 192.168.46.213:5062;branch=z9hG4bKnDrR0JLQlY6pDSOFkyYOy1
Call-ID: st5hsVxKUj
From: "mm2dev-slee"<sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0
2019-07-02 13:47:46.081201 tport.c:3051 tport_deliver() tport_deliver(0x55d2415275a0): msg 0x55d2415b91f0 (321 bytes) from udp/172.17.0.1:5060 next=(nil)
2019-07-02 13:47:46.081248 nta.c:3028 agent_recv_request() nta: received ACK sip:192.168.47.161:5060 SIP/2.0 (CSeq 1)
2019-07-02 13:47:46.081296 nta.c:3323 agent_check_request_via() nta: Via check: received=172.17.0.1
2019-07-02 13:47:46.081346 nta.c:3397 agent_aliases() nta: canonizing sip:192.168.47.161:5060 with contact
2019-07-02 13:47:46.081391 nta.c:3209 agent_recv_request() nta: ACK (1) going to existing leg
2019-07-02 13:47:46.081453 DrachtioController::processRequestInsideDialog
2019-07-02 13:47:46.081499 SipDialogController::processRequestInsideDialog: ACK irq 0x55d2415bbbd0
2019-07-02 13:47:46.081559 SipDialogController::clearIIP: clearing leg 0x55d2415b7550, irq: 0x55d2415c73d0, orq: 0, rel: 0
2019-07-02 13:47:46.081606 SipDialogController::clearIIP: clearing m_mapIrq2IIP for leg 0x55d2415b7550
2019-07-02 13:47:46.081732 SipDialogController::clearSipTimers for st5hsVxKUj
2019-07-02 13:47:46.081796 timerG: removing entry, prior to removal length: 1
2019-07-02 13:47:46.081841 timerG: removed entry, timer not set (queue is empty after removal), length: 0
2019-07-02 13:47:46.081888 timerH: removing entry, prior to removal length: 1
2019-07-02 13:47:46.081931 timerH: removed entry, timer not set (queue is empty after removal), length: 0
2019-07-02 13:47:46.082053 ClientController::removeNetTransaction: transactionId 64680ee7-2d5f-4940-9f3c-637108da7ef0; size: 2
2019-07-02 13:47:46.082124 ClientController::route_ack_request_inside_dialog - removed incoming invite transaction, map size is now: 2 request
2019-07-02 13:47:46.082182 nta.c:5892 incoming_free() nta: incoming_free(0x55d2415bbbd0)
2019-07-02 13:47:46.082210 Client::write_handler - wrote 528 bytes: system:0
2019-07-02 13:47:46.082285 tport.c:2777 tport_wakeup_pri() tport_wakeup_pri(0x55d2415275a0): events IN
2019-07-02 13:47:46.082350 tport.c:2892 tport_recv_event() tport_recv_event(0x55d2415275a0)
2019-07-02 13:47:46.082416 tport.c:3233 tport_recv_iovec() tport_recv_iovec(0x55d2415275a0) msg 0x55d2415b91f0 from (udp/172.17.0.2:5060) has 954 bytes, veclen = 1
2019-07-02 13:47:46.082872 recv 954 bytes from udp/[172.17.0.1]:36128 at 13:47:46.082519:
INFO sip:192.168.47.161:5060 SIP/2.0
Content-Length: 561
To: <sip:msml@192.168.47.161:5060>;tag=7XXHSZje9r4Kc
Contact: <sip:192.168.46.213:5062;transport=UDP>
CSeq: 2 INFO
Via: SIP/2.0/UDP 192.168.46.213:5062;branch=z9hG4bKnBJjnDoRYRKb7i8YuqvV11
Call-ID: st5hsVxKUj
Content-Type: application/msml+xml
From: "mm2dev-slee"<sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0
<?xml version='1.0' encoding='US-ASCII'?>
<msml version='1.1'>
<dialogstart target='conn:7XXHSZje9r4Kc' type='application/moml+xml' >
<play cvd:barge='true' cvd:cleardb='false' >
<audio uri='file://provisioned/bt/MM2/eng/pin_prompt.wav' />
</play>
<dtmf fdt='10s' idt='20s' edt='20s' cleardb='false' >
<pattern digits='min=1;max=27;rtk=#' format='moml+digits'>
<exit namelist='dtmf.digits dtmf.end'/>
</pattern>
<noinput><exit namelist='dtmf.digits dtmf.end'/></noinput>
<nomatch><exit namelist='dtmf.digits dtmf.end'/></nomatch>
</dtmf>
</dialogstart>
</msml>
2019-07-02 13:47:46.082970 tport.c:3051 tport_deliver() tport_deliver(0x55d2415275a0): msg 0x55d2415b91f0 (954 bytes) from udp/172.17.0.1:5060 next=(nil)
2019-07-02 13:47:46.083037 nta.c:3028 agent_recv_request() nta: received INFO sip:192.168.47.161:5060 SIP/2.0 (CSeq 2)
2019-07-02 13:47:46.083148 nta.c:3323 agent_check_request_via() nta: Via check: received=172.17.0.1
2019-07-02 13:47:46.083261 nta.c:3397 agent_aliases() nta: canonizing sip:192.168.47.161:5060 with contact
2019-07-02 13:47:46.083312 nta.c:3209 agent_recv_request() nta: INFO (2) going to existing leg
2019-07-02 13:47:46.083374 DrachtioController::processRequestInsideDialog
2019-07-02 13:47:46.083448 SipDialogController::processRequestInsideDialog: INFO irq 0x55d2415cb950
2019-07-02 13:47:46.083523 ClientController::addNetTransaction: transactionId 88777876-a8e6-448e-a497-741a2f6b03ca; size: 3
2019-07-02 13:47:46.083605 SipDialogController::addIncomingRequestTransaction - adding transactionId 88777876-a8e6-448e-a497-741a2f6b03ca for irq:0x55d2415cb950
2019-07-02 13:47:46.084447 Client::write_handler - wrote 1165 bytes: system:0
2019-07-02 13:47:46.089325 Client::read_handler read: 9f369581-9537-4149-8a1e-586f32be37d4|sip|88777876-a8e6-448e-a497-741a2f6b03ca|
SIP/2.0 200 OK
Call-ID: st5hsVxKUj
cseq: 2 INFO
from: "mm2dev-slee"<sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0
to: <sip:msml@192.168.47.161:5060>;tag=7XXHSZje9r4Kc
Content-Length: 0
2019-07-02 13:47:46.089521 Client::processMessage - got request with 4 tokens
2019-07-02 13:47:46.089593 Client::processMessage - request id 9f369581-9537-4149-8a1e-586f32be37d4, request type: sip transaction id: 88777876-a8e6-448e-a497-741a2f6b03ca, dialog id:
2019-07-02 13:47:46.089747 ClientController::addApiRequest: clientMsgId 9f369581-9537-4149-8a1e-586f32be37d4; size: 1
2019-07-02 13:47:46.089882 SipDialogController::doRespondToSipRequest thread 140714029569856
2019-07-02 13:47:46.089976 SipDialogController::findAndRemoveTransactionIdForIncomingRequest - searching transactionId 88777876-a8e6-448e-a497-741a2f6b03ca
2019-07-02 13:47:46.090078 SipDialogController::doRespondToSipRequest found incoming transaction 0x55d2415cb950
2019-07-02 13:47:46.090172 SipTransport::getContactUri - created Contact header: sip:192.168.47.161:5060
2019-07-02 13:47:46.090565 makeTags - Adding well-known header 'Call-ID' with value 'st5hsVxKUj'
2019-07-02 13:47:46.090665 makeTags - Adding well-known header 'cseq' with value '2 INFO'
2019-07-02 13:47:46.090759 makeTags - Adding well-known header 'from' with value '"mm2dev-slee"<sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0'
2019-07-02 13:47:46.090854 makeTags - Adding well-known header 'to' with value '<sip:msml@192.168.47.161:5060>;tag=7XXHSZje9r4Kc'
2019-07-02 13:47:46.090950 tport.c:3285 tport_tsend() tport_tsend(0x55d2415275a0) tpn = UDP/172.17.0.1:36128
2019-07-02 13:47:46.090999 tport.c:4085 tport_resolve() tport_resolve addrinfo = 172.17.0.1:36128
2019-07-02 13:47:46.091155 tport.c:3531 tport_send_msg() tport_vsend returned 316
2019-07-02 13:47:46.091287 send 316 bytes to udp/[172.17.0.1]:36128 at 13:47:46.091083:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.46.213:5062;branch=z9hG4bKnBJjnDoRYRKb7i8YuqvV11;received=172.17.0.1;rport=36128
From: "mm2dev-slee" <sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0
To: <sip:msml@192.168.47.161:5060>;tag=7XXHSZje9r4Kc
Call-ID: st5hsVxKUj
CSeq: 2 INFO
Content-Length: 0
2019-07-02 13:47:46.091388 nta.c:6939 incoming_reply() nta: sent 200 OK for INFO (2)
2019-07-02 13:47:46.091447 SipDialogController::doRespondToSipRequest destroying irq 0x55d2415cb950
2019-07-02 13:47:46.091555 ClientController::removeApiRequest: clientMsgId 9f369581-9537-4149-8a1e-586f32be37d4; size: 0
2019-07-02 13:47:46.092320 Client::write_handler - wrote 507 bytes: system:0
2019-07-02 13:47:46.092405 ClientController::removeNetTransaction: transactionId 88777876-a8e6-448e-a497-741a2f6b03ca; size: 2
2019-07-02 13:47:46.100094 tport.c:2777 tport_wakeup_pri() tport_wakeup_pri(0x55d2415275a0): events IN
2019-07-02 13:47:46.100216 tport.c:2892 tport_recv_event() tport_recv_event(0x55d2415275a0)
2019-07-02 13:47:46.100285 tport.c:3233 tport_recv_iovec() tport_recv_iovec(0x55d2415275a0) msg 0x55d2415cbb40 from (udp/172.17.0.2:5060) has 353 bytes, veclen = 1
2019-07-02 13:47:46.100476 recv 353 bytes from udp/[172.17.0.1]:36128 at 13:47:46.100337:
BYE sip:192.168.47.161:5060 SIP/2.0
Content-Length: 0
To: <sip:msml@192.168.47.161:5060>;tag=7XXHSZje9r4Kc
Contact: <sip:192.168.46.213:5062;transport=UDP>
CSeq: 3 BYE
Via: SIP/2.0/UDP 192.168.46.213:5062;branch=z9hG4bKnWZIl5VSR4EyfoR7bbYlH1
Call-ID: st5hsVxKUj
From: "mm2dev-slee"<sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0
2019-07-02 13:47:46.100553 tport.c:3051 tport_deliver() tport_deliver(0x55d2415275a0): msg 0x55d2415cbb40 (353 bytes) from udp/172.17.0.1:5060 next=(nil)
2019-07-02 13:47:46.100596 nta.c:3028 agent_recv_request() nta: received BYE sip:192.168.47.161:5060 SIP/2.0 (CSeq 3)
2019-07-02 13:47:46.100650 nta.c:3323 agent_check_request_via() nta: Via check: received=172.17.0.1
2019-07-02 13:47:46.100724 nta.c:3397 agent_aliases() nta: canonizing sip:192.168.47.161:5060 with contact
2019-07-02 13:47:46.100800 nta.c:3209 agent_recv_request() nta: BYE (3) going to existing leg
2019-07-02 13:47:46.100860 DrachtioController::processRequestInsideDialog
2019-07-02 13:47:46.100912 SipDialogController::processRequestInsideDialog: BYE irq 0x55d2415b5f30
2019-07-02 13:47:46.101009 ClientController::addNetTransaction: transactionId 1d379b3d-ea44-46de-99d6-06384b9e8286; size: 3
2019-07-02 13:47:46.101148 Client::write_handler - wrote 563 bytes: system:0
2019-07-02 13:47:46.101235 ClientController::removeDialog - after removing dialogs count is now: 11
2019-07-02 13:47:46.101277 SipDialogController::addIncomingRequestTransaction - adding transactionId 1d379b3d-ea44-46de-99d6-06384b9e8286 for irq:0x55d2415b5f30
2019-07-02 13:47:46.101320 SipDialogController::clearSipTimers for st5hsVxKUj
2019-07-02 13:47:46.101383 SipDialogController::clearDialog - cleared dialog id st5hsVxKUj;from-tag=1213582815620752658891.0 referenced from leg 0x55d2415b7550
2019-07-02 13:47:46.101450 No connected clients found to handle incoming cdr:stop request
2019-07-02 13:47:46.101521 SipDialog::~SipDialog - destroying sip dialog with call-id st5hsVxKUj
2019-07-02 13:47:46.101564 nta.c:4619 nta_leg_destroy() nta_leg_destroy(0x55d2415b7550)
2019-07-02 13:47:46.141259 Client::read_handler read: 17e9956e-71e0-4ce0-ba5d-999e9fb3c76b|sip|1d379b3d-ea44-46de-99d6-06384b9e8286|
SIP/2.0 200 OK
Call-ID: st5hsVxKUj
cseq: 3 BYE
from: "mm2dev-slee"<sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0
to: <sip:msml@192.168.47.161:5060>;tag=7XXHSZje9r4Kc
Content-Length: 0
2019-07-02 13:47:46.141421 Client::processMessage - got request with 4 tokens
2019-07-02 13:47:46.141484 Client::processMessage - request id 17e9956e-71e0-4ce0-ba5d-999e9fb3c76b, request type: sip transaction id: 1d379b3d-ea44-46de-99d6-06384b9e8286, dialog id:
2019-07-02 13:47:46.141566 ClientController::addApiRequest: clientMsgId 17e9956e-71e0-4ce0-ba5d-999e9fb3c76b; size: 1
2019-07-02 13:47:46.141704 SipDialogController::doRespondToSipRequest thread 140714029569856
2019-07-02 13:47:46.141863 SipDialogController::findAndRemoveTransactionIdForIncomingRequest - searching transactionId 1d379b3d-ea44-46de-99d6-06384b9e8286
2019-07-02 13:47:46.141942 SipDialogController::doRespondToSipRequest found incoming transaction 0x55d2415b5f30
2019-07-02 13:47:46.142034 SipTransport::getContactUri - created Contact header: sip:192.168.47.161:5060
2019-07-02 13:47:46.142414 makeTags - Adding well-known header 'Call-ID' with value 'st5hsVxKUj'
2019-07-02 13:47:46.142495 makeTags - Adding well-known header 'cseq' with value '3 BYE'
2019-07-02 13:47:46.142579 makeTags - Adding well-known header 'from' with value '"mm2dev-slee"<sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0'
2019-07-02 13:47:46.142664 makeTags - Adding well-known header 'to' with value '<sip:msml@192.168.47.161:5060>;tag=7XXHSZje9r4Kc'
2019-07-02 13:47:46.142783 tport.c:3285 tport_tsend() tport_tsend(0x55d2415275a0) tpn = UDP/172.17.0.1:36128
2019-07-02 13:47:46.142862 tport.c:4085 tport_resolve() tport_resolve addrinfo = 172.17.0.1:36128
2019-07-02 13:47:46.142980 tport.c:3531 tport_send_msg() tport_vsend returned 315
2019-07-02 13:47:46.143133 send 315 bytes to udp/[172.17.0.1]:36128 at 13:47:46.142910:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.46.213:5062;branch=z9hG4bKnWZIl5VSR4EyfoR7bbYlH1;received=172.17.0.1;rport=36128
From: "mm2dev-slee" <sip:mm2dev-slee@192.168.46.213>;tag=1213582815620752658891.0
To: <sip:msml@192.168.47.161:5060>;tag=7XXHSZje9r4Kc
Call-ID: st5hsVxKUj
CSeq: 3 BYE
Content-Length: 0
2019-07-02 13:47:46.143213 nta.c:6939 incoming_reply() nta: sent 200 OK for BYE (3)
2019-07-02 13:47:46.143296 SipDialogController::doRespondToSipRequest destroying irq 0x55d2415b5f30
2019-07-02 13:47:46.143400 ClientController::removeApiRequest: clientMsgId 17e9956e-71e0-4ce0-ba5d-999e9fb3c76b; size: 0
2019-07-02 13:47:46.143540 Client::write_handler - wrote 506 bytes: system:0
2019-07-02 13:47:46.143621 ClientController::removeNetTransaction: transactionId 1d379b3d-ea44-46de-99d6-06384b9e8286; size: 2
2019-07-02 13:47:46.144593 Client::read_handler read: 0d089ec7-1d14-41bd-9582-400f28c728cd|sip||d04e7e68-1772-1238-33bc-0242ac110002;from-tag=6m4rQ41acge1g
BYE sip:placeholder SIP/2.0
Content-Length: 0
2019-07-02 13:47:46.144756 Client::processMessage - got request with 4 tokens
2019-07-02 13:47:46.144804 Client::processMessage - request id 0d089ec7-1d14-41bd-9582-400f28c728cd, request type: sip transaction id: , dialog id: d04e7e68-1772-1238-33bc-0242ac110002;from-tag=6m4rQ41acge1g
2019-07-02 13:47:46.144870 Client::processMessage - sending a request inside a dialog (dialogId provided)
2019-07-02 13:47:46.144928 ClientController::addAppTransaction: transactionId b6378db0-de8f-4c29-924c-fd74f10e4d38; size: 1
2019-07-02 13:47:46.145005 ClientController::addApiRequest: clientMsgId 0d089ec7-1d14-41bd-9582-400f28c728cd; size: 1
2019-07-02 13:47:46.145126 SipDialogController::doSendRequestInsideDialog dialog id: d04e7e68-1772-1238-33bc-0242ac110002;from-tag=6m4rQ41acge1g
2019-07-02 13:47:46.145512 SipDialogController::doSendRequestInsideDialog - defaulting request uri to sip:1234@192.168.47.134:5060;transport=udp
2019-07-02 13:47:46.145606 DrachtioController::findTportForSubscription: no transport found for 1234@192.168.47.134
2019-07-02 13:47:46.145681 nta.c:2813 nta_tpn_by_url() nta: selecting scheme sip
2019-07-02 13:47:46.145756 tport.c:3285 tport_tsend() tport_tsend(0x55d2415275a0) tpn = udp/192.168.47.134:5060
2019-07-02 13:47:46.145846 tport.c:4085 tport_resolve() tport_resolve addrinfo = 192.168.47.134:5060
2019-07-02 13:47:46.145974 tport.c:3531 tport_send_msg() tport_vsend returned 345
2019-07-02 13:47:46.146116 send 345 bytes to udp/[192.168.47.134]:5060 at 13:47:46.145892:
BYE sip:1234@192.168.47.134:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.47.161;rport;branch=z9hG4bKvtZyjKZa91mep
Max-Forwards: 70
From: <sip:mm2dev-slee@192.168.47.161:5060>;tag=6m4rQ41acge1g
To: <sip:1234@192.168.47.134:5060>;tag=Bjtj22yXe9F6Q
Call-ID: d04e7e68-1772-1238-33bc-0242ac110002
CSeq: 6483842 BYE
Content-Length: 0
2019-07-02 13:47:46.146186 nta.c:8470 outgoing_send() nta: sent BYE (6483842) to udp/192.168.47.134:5060
2019-07-02 13:47:46.146306 tport.c:4199 tport_pend() tport_pend(0x55d2415275a0): pending 0x55d2415b09d0 for udp/172.17.0.2:5060 (already 0)
2019-07-02 13:47:46.146396 SipDialogController::doSendRequestInsideDialog - created orq 0x55d2415ae0a0 sending BYE to sip:1234@192.168.47.134:5060;transport=udp
2019-07-02 13:47:46.146541 SipDialogController::addRIP adding orq 0x55d2415ae0a0
2019-07-02 13:47:46.146619 No connected clients found to handle incoming cdr:stop request
2019-07-02 13:47:46.146699 ClientController::removeApiRequest: clientMsgId 0d089ec7-1d14-41bd-9582-400f28c728cd; size: 0
2019-07-02 13:47:46.146839 Client::write_handler - wrote 536 bytes: system:0
2019-07-02 13:47:46.163972 tport.c:2777 tport_wakeup_pri() tport_wakeup_pri(0x55d2415275a0): events IN
2019-07-02 13:47:46.164108 tport.c:2892 tport_recv_event() tport_recv_event(0x55d2415275a0)
2019-07-02 13:47:46.164194 tport.c:3233 tport_recv_iovec() tport_recv_iovec(0x55d2415275a0) msg 0x55d2415ab710 from (udp/172.17.0.2:5060) has 485 bytes, veclen = 1
2019-07-02 13:47:46.164663 recv 485 bytes from udp/[192.168.47.134]:5060 at 13:47:46.164361:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.47.161;rport=60574;branch=z9hG4bKvtZyjKZa91mep
From: <sip:mm2dev-slee@192.168.47.161:5060>;tag=6m4rQ41acge1g
To: <sip:1234@192.168.47.134:5060>;tag=Bjtj22yXe9F6Q
Call-ID: d04e7e68-1772-1238-33bc-0242ac110002
CSeq: 6483842 BYE
User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20190606T174518Z~813a37d844~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REFER, NOTIFY
Supported: timer, path, replaces
Content-Length: 0
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment