Created
July 2, 2019 13:54
-
-
Save phildunks/035dafadebd3ec52c1baf58b92d21cc1 to your computer and use it in GitHub Desktop.
Race condition logs.
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
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