recv 763 bytes from udp/[172.19.50.4]:3861 at 21:39:24.424656: ------------------------------------------------------------------------ REGISTER sip:pbx.[anonym].net SIP/2.0 Authorization: Digest username="9590206",realm="pbx.[anonym].net",nonce="d9fb4777-4364-4a78-b513-5925e62367b5",response="04f549169bce4aeaff37a10bcedaff1e",uri="sip:pbx.[anonym].net",qop=auth,cnonce="719b57f454db5b017ede009033060682",nc=0000037c,algorithm=MD5 Via: SIP/2.0/UDP 172.19.50.4:3861;branch=z9hG4bK-03B444A8;rport From: ;tag=2770968073 To: Call-ID: c7e2bd8b47e55b014639009033060682 CSeq: 3458 REGISTER Contact: ;expires=120 Accept: innovaphone/data Content-Length: 0 Expires: 120 Max-Forwards: 70 User-Agent: (innovaphone IP800/11r2 sr15 [11.3587/113587/106]) Allow-Events: reg,dialog,message-summary,presence ------------------------------------------------------------------------ send 544 bytes to udp/[172.19.50.4]:3861 at 21:39:24.467160: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.19.50.4:3861;branch=z9hG4bK-03B444A8;rport=3861 From: ;tag=2770968073 To: ;tag=Kr0DjHvjgKBee Call-ID: c7e2bd8b47e55b014639009033060682 CSeq: 3458 REGISTER Contact: ;expires=120 Date: Sun, 11 Nov 2018 20:39:24 GMT User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ recv 496 bytes from udp/[172.19.51.21]:5060 at 21:39:25.103011: ------------------------------------------------------------------------ SUBSCRIBE sip:13@172.19.50.3:5060 SIP/2.0 Via: SIP/2.0/UDP 172.19.51.21:5060;branch=z9hG4bK-B89D31D5;rport From: ;tag=201447844 To: ;tag=IVbQih4CEMYf Call-ID: 6dc598b07ce85b01209e0090332616fc@4 CSeq: 2067 SUBSCRIBE Contact: Accept: application/dialog-info+xml Content-Length: 0 Expires: 119 Max-Forwards: 70 User-Agent: (innovaphone IP240/12r1 sr26 [12.1257/121257/301]) Event: dialog ------------------------------------------------------------------------ send 710 bytes to udp/[172.19.51.21]:5060 at 21:39:25.106733: ------------------------------------------------------------------------ SIP/2.0 202 Accepted Via: SIP/2.0/UDP 172.19.51.21:5060;branch=z9hG4bK-B89D31D5;rport=5060 From: ;tag=201447844 To: ;tag=IVbQih4CEMYf Call-ID: 6dc598b07ce85b01209e0090332616fc@4 CSeq: 2067 SUBSCRIBE Contact: Expires: 119 User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Subscription-State: active;expires=119 Content-Length: 0 ------------------------------------------------------------------------ send 953 bytes to udp/[172.19.51.21]:5060 at 21:39:25.110063: ------------------------------------------------------------------------ NOTIFY sip:11@172.19.51.21:5060;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 172.19.50.3;rport;branch=z9hG4bKgpm6BHy2eKp2K Max-Forwards: 70 From: ;tag=IVbQih4CEMYf To: ;tag=201447844 Call-ID: 6dc598b07ce85b01209e0090332616fc@4 CSeq: 1360378251 NOTIFY Contact: User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Event: dialog Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Subscription-State: active;expires=119 Content-Type: application/dialog-info+xml Content-Length: 150 ------------------------------------------------------------------------ recv 352 bytes from udp/[172.19.51.21]:5060 at 21:39:25.113659: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.19.50.3;rport;branch=z9hG4bKgpm6BHy2eKp2K;received=172.19.50.3 From: ;tag=IVbQih4CEMYf To: ;tag=201447844 Call-ID: 6dc598b07ce85b01209e0090332616fc@4 CSeq: 1360378251 NOTIFY Content-Length: 0 Server: (innovaphone IP240/12r1 sr26 [12.1257/121257/301]) ------------------------------------------------------------------------ recv 496 bytes from udp/[172.19.51.21]:5060 at 21:39:25.443007: ------------------------------------------------------------------------ SUBSCRIBE sip:12@172.19.50.3:5060 SIP/2.0 Via: SIP/2.0/UDP 172.19.51.21:5060;branch=z9hG4bK-B89D31D6;rport From: ;tag=201447843 To: ;tag=KwAnCbiD8uGu Call-ID: e54e60b07ce85b011e9e0090332616fc@3 CSeq: 2067 SUBSCRIBE Contact: Accept: application/dialog-info+xml Content-Length: 0 Expires: 119 Max-Forwards: 70 User-Agent: (innovaphone IP240/12r1 sr26 [12.1257/121257/301]) Event: dialog ------------------------------------------------------------------------ send 710 bytes to udp/[172.19.51.21]:5060 at 21:39:25.446691: ------------------------------------------------------------------------ SIP/2.0 202 Accepted Via: SIP/2.0/UDP 172.19.51.21:5060;branch=z9hG4bK-B89D31D6;rport=5060 From: ;tag=201447843 To: ;tag=KwAnCbiD8uGu Call-ID: e54e60b07ce85b011e9e0090332616fc@3 CSeq: 2067 SUBSCRIBE Contact: Expires: 119 User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Subscription-State: active;expires=119 Content-Length: 0 ------------------------------------------------------------------------ send 953 bytes to udp/[172.19.51.21]:5060 at 21:39:25.450086: ------------------------------------------------------------------------ NOTIFY sip:11@172.19.51.21:5060;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 172.19.50.3;rport;branch=z9hG4bKHZDZDcF6BvcNF Max-Forwards: 70 From: ;tag=KwAnCbiD8uGu To: ;tag=201447843 Call-ID: e54e60b07ce85b011e9e0090332616fc@3 CSeq: 1360378252 NOTIFY Contact: User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Event: dialog Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Subscription-State: active;expires=119 Content-Type: application/dialog-info+xml Content-Length: 150 ------------------------------------------------------------------------ recv 352 bytes from udp/[172.19.51.21]:5060 at 21:39:25.456350: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.19.50.3;rport;branch=z9hG4bKHZDZDcF6BvcNF;received=172.19.50.3 From: ;tag=KwAnCbiD8uGu To: ;tag=201447843 Call-ID: e54e60b07ce85b011e9e0090332616fc@3 CSeq: 1360378252 NOTIFY Content-Length: 0 Server: (innovaphone IP240/12r1 sr26 [12.1257/121257/301]) ------------------------------------------------------------------------ recv 1308 bytes from udp/[172.19.50.4]:3861 at 21:39:47.946806: ------------------------------------------------------------------------ INVITE sip:0108008080800@pbx.[anonym].net;user=phone SIP/2.0 Via: SIP/2.0/UDP 172.19.50.4:3861;branch=z9hG4bK-03B444AA;rport From: ;tag=2770968075 To: Call-ID: 10d5c69393e85b01a048009033060682@410 CSeq: 1133815520 INVITE Contact: Allow: REGISTER,SUBSCRIBE,NOTIFY,INVITE,ACK,PRACK,OPTIONS,BYE,CANCEL,REFER,INFO,UPDATE,PUBLISH Content-Length: 559 Content-Type: application/sdp Max-Forwards: 69 Supported: 100rel,replaces,privacy,timer,from-change,histinfo,answermode User-Agent: (innovaphone IP800/11r2 sr15 [11.3587/113587/106]) P-Preferred-Identity: P-Sig-Options: Overlap-Dialing v=0 o=- 1040 1 IN IP4 172.19.50.4 s=- t=0 0 m=audio 16686 RTP/SAVP 8 18 4 0 97 101 c=IN IP4 172.19.50.4 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:4 G723/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:97 CLEARMODE/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:18 annexb=no a=fmtp:101 0-15 a=ptime:30 a=silenceSupp:off - - - - a=sendrecv a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:X0jxiZ/k7DPggObqIRzhtGG43JCiVNd94vDSguFd|2^31 a=fingerprint:sha-256 A9:4C:E4:69:65:05:D5:43:C7:E5:0A:99:E5:5B:2E:01:80:EE:81:49:C0:C3:47:3C:10:66:B5:FF:8B:5D:BA:5F ------------------------------------------------------------------------ 2018-11-11 21:39:47.935673 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/9590206@pbx.[anonym].net [8e1aa3c0-0313-4d15-baa1-1f2fa9ab32b7] 2018-11-11 21:39:47.935673 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9590206@pbx.[anonym].net) Running State Change CS_NEW (Cur 1 Tot 21) 2018-11-11 21:39:47.935673 [DEBUG] sofia.c:10080 sofia/internal/9590206@pbx.[anonym].net receiving invite from 172.19.50.4:3861 version: 1.8.2 -3-a98a958ac3 64bit 2018-11-11 21:39:47.935673 [DEBUG] sofia.c:10251 IP 172.19.50.4 Rejected by acl "domains". Falling back to Digest auth. 2018-11-11 21:39:47.935673 [WARNING] sofia_reg.c:1793 SIP auth challenge (INVITE) on sofia profile 'internal' for [0108008080800@pbx.[anonym].net] from ip 172.19.50.4 2018-11-11 21:39:47.935673 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/9590206@pbx.[anonym].net) State NEW send 811 bytes to udp/[172.19.50.4]:3861 at 21:39:47.952458: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 172.19.50.4:3861;branch=z9hG4bK-03B444AA;rport=3861 From: ;tag=2770968075 To: ;tag=m1S6KcDpDv10S Call-ID: 10d5c69393e85b01a048009033060682@410 CSeq: 1133815520 INVITE User-Agent: FreeSWITCH Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Proxy-Authenticate: Digest realm="pbx.[anonym].net", nonce="05c25e77-130a-4164-aae4-06486050c13a", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2018-11-11 21:39:47.935673 [DEBUG] sofia.c:2413 detaching session 8e1aa3c0-0313-4d15-baa1-1f2fa9ab32b7 recv 402 bytes from udp/[172.19.50.4]:3861 at 21:39:47.954818: ------------------------------------------------------------------------ ACK sip:0108008080800@pbx.[anonym].net;user=phone SIP/2.0 Via: SIP/2.0/UDP 172.19.50.4:3861;branch=z9hG4bK-03B444AA;rport From: ;tag=2770968075 To: ;tag=m1S6KcDpDv10S Call-ID: 10d5c69393e85b01a048009033060682@410 CSeq: 1133815520 ACK Contact: Content-Length: 0 Max-Forwards: 70 ------------------------------------------------------------------------ recv 1593 bytes from udp/[172.19.50.4]:3861 at 21:39:47.957573: ------------------------------------------------------------------------ INVITE sip:0108008080800@pbx.[anonym].net;user=phone SIP/2.0 Proxy-Authorization: Digest username="9590206",realm="pbx.[anonym].net",nonce="05c25e77-130a-4164-aae4-06486050c13a",response="5bc96013997736bfe9ae31f77fbf613e",uri="sip:0108008080800@pbx.[anonym].net;user=phone",qop=auth,cnonce="719b57f454db5b017ede009033060682",nc=00000001,algorithm=MD5 Via: SIP/2.0/UDP 172.19.50.4:3861;branch=z9hG4bK-03B444AB;rport From: ;tag=2770968075 To: Call-ID: 10d5c69393e85b01a048009033060682@410 CSeq: 1133815521 INVITE Contact: Allow: REGISTER,SUBSCRIBE,NOTIFY,INVITE,ACK,PRACK,OPTIONS,BYE,CANCEL,REFER,INFO,UPDATE,PUBLISH Content-Length: 559 Content-Type: application/sdp Max-Forwards: 69 Supported: 100rel,replaces,privacy,timer,from-change,histinfo,answermode User-Agent: (innovaphone IP800/11r2 sr15 [11.3587/113587/106]) P-Preferred-Identity: P-Sig-Options: Overlap-Dialing v=0 o=- 1040 1 IN IP4 172.19.50.4 s=- t=0 0 m=audio 16686 RTP/SAVP 8 18 4 0 97 101 c=IN IP4 172.19.50.4 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:4 G723/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:97 CLEARMODE/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:18 annexb=no a=fmtp:101 0-15 a=ptime:30 a=silenceSupp:off - - - - a=sendrecv a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:X0jxiZ/k7DPggObqIRzhtGG43JCiVNd94vDSguFd|2^31 a=fingerprint:sha-256 A9:4C:E4:69:65:05:D5:43:C7:E5:0A:99:E5:5B:2E:01:80:EE:81:49:C0:C3:47:3C:10:66:B5:FF:8B:5D:BA:5F ------------------------------------------------------------------------ 2018-11-11 21:39:47.955698 [DEBUG] sofia.c:2522 Re-attaching to session 8e1aa3c0-0313-4d15-baa1-1f2fa9ab32b7 2018-11-11 21:39:47.955698 [DEBUG] sofia.c:10080 sofia/internal/9590206@pbx.[anonym].net receiving invite from 172.19.50.4:3861 version: 1.8.2 -3-a98a958ac3 64bit 2018-11-11 21:39:47.955698 [DEBUG] sofia.c:10251 IP 172.19.50.4 Rejected by acl "domains". Falling back to Digest auth. 2018-11-11 21:39:48.015666 [DEBUG] sofia.c:7291 Channel sofia/internal/9590206@pbx.[anonym].net entering state [received][100] 2018-11-11 21:39:48.015666 [DEBUG] sofia.c:7301 Remote SDP: v=0 o=- 1040 1 IN IP4 172.19.50.4 s=- t=0 0 m=audio 16686 RTP/SAVP 8 18 4 0 97 101 c=IN IP4 172.19.50.4 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:97 CLEARMODE/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=silenceSupp:off - - - - a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:X0jxiZ/k7DPggObqIRzhtGG43JCiVNd94vDSguFd|2^31 a=fingerprint:sha-256 A9:4C:E4:69:65:05:D5:43:C7:E5:0A:99:E5:5B:2E:01:80:EE:81:49:C0:C3:47:3C:10:66:B5:FF:8B:5D:BA:5F 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[opus:116:48000:20:0:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[G722:9:8000:20:64000:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMA:8:8000:20:64000:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5514 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729:18:8000:30:8000:1]/[opus:116:48000:20:0:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729:18:8000:30:8000:1]/[G722:9:8000:20:64000:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729:18:8000:30:8000:1]/[PCMA:8:8000:20:64000:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G723:4:8000:30:6300:1]/[opus:116:48000:20:0:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G723:4:8000:30:6300:1]/[G722:9:8000:20:64000:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G723:4:8000:30:6300:1]/[PCMA:8:8000:20:64000:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[opus:116:48000:20:0:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[G722:9:8000:20:64000:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMA:8:8000:20:64000:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [CLEARMODE:97:8000:30:0:1]/[opus:116:48000:20:0:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [CLEARMODE:97:8000:30:0:1]/[G722:9:8000:20:64000:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [CLEARMODE:97:8000:30:0:1]/[PCMA:8:8000:20:64000:1] 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5585 Substituting codec PCMA@30i@8000h@1c 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:3781 Set Codec sofia/internal/9590206@pbx.[anonym].net PCMA/8000 30 ms 240 samples 64000 bits 1 channels 2018-11-11 21:39:48.015666 [DEBUG] switch_core_codec.c:111 sofia/internal/9590206@pbx.[anonym].net Original read codec set to PCMA:8 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5737 Set telephone-event payload to 101@8000 2018-11-11 21:39:48.015666 [DEBUG] switch_core_media.c:5795 sofia/internal/9590206@pbx.[anonym].net Set 2833 dtmf send payload to 101 recv payload to 101 2018-11-11 21:39:48.015666 [DEBUG] sofia.c:7716 (sofia/internal/9590206@pbx.[anonym].net) State Change CS_NEW -> CS_INIT 2018-11-11 21:39:48.015666 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9590206@pbx.[anonym].net) Running State Change CS_INIT (Cur 1 Tot 21) 2018-11-11 21:39:48.015666 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/9590206@pbx.[anonym].net) State INIT 2018-11-11 21:39:48.015666 [DEBUG] mod_sofia.c:93 sofia/internal/9590206@pbx.[anonym].net SOFIA INIT 2018-11-11 21:39:48.015666 [DEBUG] switch_core_state_machine.c:40 sofia/internal/9590206@pbx.[anonym].net Standard INIT 2018-11-11 21:39:48.015666 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/9590206@pbx.[anonym].net) State Change CS_INIT -> CS_ROUTING 2018-11-11 21:39:48.015666 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/9590206@pbx.[anonym].net) State INIT going to sleep 2018-11-11 21:39:48.015666 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9590206@pbx.[anonym].net) Running State Change CS_ROUTING (Cur 1 Tot 21) 2018-11-11 21:39:48.015666 [DEBUG] switch_channel.c:2249 (sofia/internal/9590206@pbx.[anonym].net) Callstate Change DOWN -> RINGING 2018-11-11 21:39:48.015666 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/9590206@pbx.[anonym].net) State ROUTING 2018-11-11 21:39:48.015666 [DEBUG] mod_sofia.c:154 sofia/internal/9590206@pbx.[anonym].net SOFIA ROUTING 2018-11-11 21:39:48.015666 [DEBUG] switch_core_state_machine.c:236 sofia/internal/9590206@pbx.[anonym].net Standard ROUTING 2018-11-11 21:39:48.015666 [INFO] mod_dialplan_xml.c:637 Processing 9590206 < 31>->0108008080800 in context pbx.[anonym].net send 307 bytes to udp/[172.19.50.4]:3861 at 21:39:48.022253: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.19.50.4:3861;branch=z9hG4bK-03B444AB;rport=3861 From: ;tag=2770968075 To: Call-ID: 10d5c69393e85b01a048009033060682@410 CSeq: 1133815521 INVITE User-Agent: FreeSWITCH Content-Length: 0 ------------------------------------------------------------------------ Dialplan: sofia/internal/9590206@pbx.[anonym].net parsing [pbx.[anonym].net->user_exists] continue=true Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [user_exists] () =~ // break=on-false Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE EXECUTE sofia/internal/9590206@pbx.[anonym].net set(user_exists=false) 2018-11-11 21:39:48.115661 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [user_exists]=[false] Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false Dialplan: sofia/internal/9590206@pbx.[anonym].net parsing [pbx.[anonym].net->caller-details] continue=true Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(caller_destination=${destination_number}) INLINE EXECUTE sofia/internal/9590206@pbx.[anonym].net set(caller_destination=0108008080800) 2018-11-11 21:39:48.115661 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [caller_destination]=[0108008080800] Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(caller_id_name=${caller_id_name}) INLINE EXECUTE sofia/internal/9590206@pbx.[anonym].net set(caller_id_name=9590206) 2018-11-11 21:39:48.115661 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [caller_id_name]=[9590206] Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(caller_id_number=${caller_id_number}) INLINE EXECUTE sofia/internal/9590206@pbx.[anonym].net set(caller_id_number=9590206) 2018-11-11 21:39:48.115661 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [caller_id_number]=[9590206] Dialplan: sofia/internal/9590206@pbx.[anonym].net parsing [pbx.[anonym].net->variables] continue=true Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [variables] () =~ // break=on-false Dialplan: sofia/internal/9590206@pbx.[anonym].net Action export(origination_callee_id_name=${destination_number}) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/9590206@pbx.[anonym].net parsing [pbx.[anonym].net->call-direction] continue=true Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net ANTI-Action export(call_direction=local) Dialplan: sofia/internal/9590206@pbx.[anonym].net parsing [pbx.[anonym].net->user_record] continue=true Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [user_record] () =~ // break=on-false Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE EXECUTE sofia/internal/9590206@pbx.[anonym].net set(user_record=) 2018-11-11 21:39:48.175690 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [user_record]=[UNDEF] Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE EXECUTE sofia/internal/9590206@pbx.[anonym].net set(from_user_exists=true) 2018-11-11 21:39:48.195724 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [from_user_exists]=[true] Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE EXECUTE sofia/internal/9590206@pbx.[anonym].net set(from_user_record=) 2018-11-11 21:39:48.215720 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [from_user_record]=[UNDEF] Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false Dialplan: sofia/internal/9590206@pbx.[anonym].net parsing [pbx.[anonym].net->redial] continue=true Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [redial] destination_number(0108008080800) =~ /^(redial|\*870)$/ break=on-true Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [redial] () =~ // break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/9590206@pbx.[anonym].net parsing [pbx.[anonym].net->speed_dial] continue=false Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [speed_dial] destination_number(0108008080800) =~ /^\*0(.*)$/ break=on-false Dialplan: sofia/internal/9590206@pbx.[anonym].net parsing [pbx.[anonym].net->default_caller_id] continue=true Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE EXECUTE sofia/internal/9590206@pbx.[anonym].net set(emergency_caller_id_name=) 2018-11-11 21:39:48.215720 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [emergency_caller_id_name]=[UNDEF] Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE EXECUTE sofia/internal/9590206@pbx.[anonym].net set(emergency_caller_id_number=) 2018-11-11 21:39:48.215720 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [emergency_caller_id_number]=[UNDEF] Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [default_caller_id] ${outbound_caller_id_number}() =~ /^$/ break=never Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(outbound_caller_id_name=${default_outbound_caller_id_name}) INLINE EXECUTE sofia/internal/9590206@pbx.[anonym].net set(outbound_caller_id_name=) 2018-11-11 21:39:48.215720 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [outbound_caller_id_name]=[UNDEF] Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(outbound_caller_id_number=${default_outbound_caller_id_number}) INLINE EXECUTE sofia/internal/9590206@pbx.[anonym].net set(outbound_caller_id_number=) 2018-11-11 21:39:48.215720 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [outbound_caller_id_number]=[UNDEF] Dialplan: sofia/internal/9590206@pbx.[anonym].net parsing [pbx.[anonym].net->49[anonym]156.d] continue=false Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [49[anonym]156.d] ${user_exists}(false) =~ /false/ break=on-false Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (FAIL) [49[anonym]156.d] ${sip_from_user}(9590206) =~ /12/ break=on-false Dialplan: sofia/internal/9590206@pbx.[anonym].net parsing [pbx.[anonym].net->+49[anonym]206.01d] continue=false Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [+49[anonym]206.01d] ${user_exists}(false) =~ /false/ break=on-false Dialplan: sofia/internal/9590206@pbx.[anonym].net Regex (PASS) [+49[anonym]206.01d] destination_number(0108008080800) =~ /^01(\d+)$/ break=on-false Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(sip_h_X-accountcode=${accountcode}) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action export(call_direction=outbound) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action unset(call_timeout) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(hangup_after_bridge=true) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(effective_caller_id_name=${outbound_caller_id_name}) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(effective_caller_id_number=${outbound_caller_id_number}) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(inherit_codec=true) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(ignore_display_updates=true) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(callee_id_number=08008080800) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(continue_on_fail=true) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action set(outbound_prefix=01) Dialplan: sofia/internal/9590206@pbx.[anonym].net Action bridge(sofia/gateway/737888c4-6119-4b50-9b6d-176732c5fb2d/08008080800) 2018-11-11 21:39:48.215720 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/9590206@pbx.[anonym].net) State Change CS_ROUTING -> CS_EXECUTE 2018-11-11 21:39:48.215720 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/9590206@pbx.[anonym].net) State ROUTING going to sleep 2018-11-11 21:39:48.215720 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9590206@pbx.[anonym].net) Running State Change CS_EXECUTE (Cur 1 Tot 21) 2018-11-11 21:39:48.215720 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/9590206@pbx.[anonym].net) State EXECUTE 2018-11-11 21:39:48.215720 [DEBUG] mod_sofia.c:209 sofia/internal/9590206@pbx.[anonym].net SOFIA EXECUTE 2018-11-11 21:39:48.215720 [DEBUG] switch_core_state_machine.c:328 sofia/internal/9590206@pbx.[anonym].net Standard EXECUTE EXECUTE sofia/internal/9590206@pbx.[anonym].net export(origination_callee_id_name=0108008080800) 2018-11-11 21:39:48.215720 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[0108008080800] EXECUTE sofia/internal/9590206@pbx.[anonym].net set(RFC2822_DATE=Sun, 11 Nov 2018 21:39:48 +0100) 2018-11-11 21:39:48.215720 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [RFC2822_DATE]=[Sun, 11 Nov 2018 21:39:48 +0100] EXECUTE sofia/internal/9590206@pbx.[anonym].net export(call_direction=local) 2018-11-11 21:39:48.215720 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[local] EXECUTE sofia/internal/9590206@pbx.[anonym].net hash(insert/pbx.[anonym].net-last_dial/9590206/0108008080800) EXECUTE sofia/internal/9590206@pbx.[anonym].net set(sip_h_X-accountcode=) 2018-11-11 21:39:48.235726 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [sip_h_X-accountcode]=[UNDEF] EXECUTE sofia/internal/9590206@pbx.[anonym].net export(call_direction=outbound) 2018-11-11 21:39:48.235726 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[outbound] EXECUTE sofia/internal/9590206@pbx.[anonym].net unset(call_timeout) 2018-11-11 21:39:48.235726 [DEBUG] mod_dptools.c:1743 UNSET [call_timeout] EXECUTE sofia/internal/9590206@pbx.[anonym].net set(hangup_after_bridge=true) 2018-11-11 21:39:48.235726 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [hangup_after_bridge]=[true] EXECUTE sofia/internal/9590206@pbx.[anonym].net set(effective_caller_id_name=) 2018-11-11 21:39:48.235726 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [effective_caller_id_name]=[UNDEF] EXECUTE sofia/internal/9590206@pbx.[anonym].net set(effective_caller_id_number=) 2018-11-11 21:39:48.235726 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [effective_caller_id_number]=[UNDEF] EXECUTE sofia/internal/9590206@pbx.[anonym].net set(inherit_codec=true) 2018-11-11 21:39:48.235726 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [inherit_codec]=[true] EXECUTE sofia/internal/9590206@pbx.[anonym].net set(ignore_display_updates=true) 2018-11-11 21:39:48.235726 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [ignore_display_updates]=[true] EXECUTE sofia/internal/9590206@pbx.[anonym].net set(callee_id_number=08008080800) 2018-11-11 21:39:48.235726 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [callee_id_number]=[08008080800] EXECUTE sofia/internal/9590206@pbx.[anonym].net set(continue_on_fail=true) 2018-11-11 21:39:48.235726 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [continue_on_fail]=[true] EXECUTE sofia/internal/9590206@pbx.[anonym].net set(outbound_prefix=01) 2018-11-11 21:39:48.235726 [DEBUG] mod_dptools.c:1598 SET sofia/internal/9590206@pbx.[anonym].net [outbound_prefix]=[01] EXECUTE sofia/internal/9590206@pbx.[anonym].net bridge(sofia/gateway/737888c4-6119-4b50-9b6d-176732c5fb2d/08008080800) 2018-11-11 21:39:48.235726 [DEBUG] switch_channel.c:1250 sofia/internal/9590206@pbx.[anonym].net EXPORTING[export_vars] [domain_name]=[pbx.[anonym].net] to event 2018-11-11 21:39:48.235726 [DEBUG] switch_channel.c:1250 sofia/internal/9590206@pbx.[anonym].net EXPORTING[export_vars] [origination_callee_id_name]=[0108008080800] to event 2018-11-11 21:39:48.235726 [DEBUG] switch_channel.c:1250 sofia/internal/9590206@pbx.[anonym].net EXPORTING[export_vars] [call_direction]=[outbound] to event 2018-11-11 21:39:48.235726 [DEBUG] switch_channel.c:1250 sofia/internal/9590206@pbx.[anonym].net EXPORTING[export_vars] [call_direction]=[outbound] to event 2018-11-11 21:39:48.235726 [DEBUG] switch_ivr_originate.c:2204 Parsing global variables 2018-11-11 21:39:48.235726 [NOTICE] switch_channel.c:1104 New Channel sofia/external/08008080800 [6f89fc02-3687-4576-a315-739df3bd4ed3] 2018-11-11 21:39:48.235726 [DEBUG] mod_sofia.c:5028 (sofia/external/08008080800) State Change CS_NEW -> CS_INIT 2018-11-11 21:39:48.235726 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08008080800) Running State Change CS_INIT (Cur 2 Tot 22) 2018-11-11 21:39:48.235726 [DEBUG] switch_core_state_machine.c:627 (sofia/external/08008080800) State INIT 2018-11-11 21:39:48.235726 [DEBUG] mod_sofia.c:93 sofia/external/08008080800 SOFIA INIT 2018-11-11 21:39:48.255701 [DEBUG] sofia_glue.c:1299 sofia/external/08008080800 sending invite version: 1.8.2 -3-a98a958ac3 64bit Local SDP: v=0 o=FreeSWITCH 1541947070 1541947071 IN IP4 172.19.50.3 s=FreeSWITCH c=IN IP4 172.19.50.3 t=0 0 m=audio 21718 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:30 a=sendrecv m=audio 21718 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 a=sendrecv 2018-11-11 21:39:48.255701 [DEBUG] switch_core_state_machine.c:40 sofia/external/08008080800 Standard INIT 2018-11-11 21:39:48.255701 [DEBUG] switch_core_state_machine.c:48 (sofia/external/08008080800) State Change CS_INIT -> CS_ROUTING 2018-11-11 21:39:48.255701 [DEBUG] switch_core_state_machine.c:627 (sofia/external/08008080800) State INIT going to sleep 2018-11-11 21:39:48.255701 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08008080800) Running State Change CS_ROUTING (Cur 2 Tot 22) send 1264 bytes to udp/[217.0.27.32]:5060 at 21:39:48.257450: ------------------------------------------------------------------------ INVITE sip:08008080800@tel.t-online.de SIP/2.0 Via: SIP/2.0/UDP 172.19.50.3:5080;rport;branch=z9hG4bKjvmm45ygZaUcc Max-Forwards: 68 From: "9590206" ;tag=4vBe8B7SDN8SQ To: Call-ID: c5a934a7-6094-1237-1193-000db9478a88 CSeq: 130648330 INVITE Contact: User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 381 P-Sig-Options: Overlap-Dialing X-FS-Support: update_display,send_info Remote-Party-ID: "9590206" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1541947070 1541947071 IN IP4 172.19.50.3 s=FreeSWITCH c=IN IP4 172.19.50.3 t=0 0 m=audio 21718 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:30 m=audio 21718 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 ------------------------------------------------------------------------ 2018-11-11 21:39:48.255701 [DEBUG] switch_core_state_machine.c:643 (sofia/external/08008080800) State ROUTING 2018-11-11 21:39:48.255701 [DEBUG] mod_sofia.c:154 sofia/external/08008080800 SOFIA ROUTING 2018-11-11 21:39:48.255701 [DEBUG] switch_ivr_originate.c:67 (sofia/external/08008080800) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-11-11 21:39:48.255701 [DEBUG] switch_core_state_machine.c:643 (sofia/external/08008080800) State ROUTING going to sleep 2018-11-11 21:39:48.255701 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08008080800) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 22) 2018-11-11 21:39:48.255701 [DEBUG] sofia.c:7291 Channel sofia/external/08008080800 entering state [calling][0] 2018-11-11 21:39:48.255701 [DEBUG] switch_core_state_machine.c:662 (sofia/external/08008080800) State CONSUME_MEDIA 2018-11-11 21:39:48.255701 [DEBUG] switch_core_state_machine.c:662 (sofia/external/08008080800) State CONSUME_MEDIA going to sleep recv 525 bytes from udp/[217.0.27.32]:5060 at 21:39:48.373846: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required 02035034C Via: SIP/2.0/UDP 172.19.50.3:5080;received=172.19.50.3;rport=5080;branch=z9hG4bKjvmm45ygZaUcc To: ;tag=h7g4Esbg_662a8891012f38ace0d410e96e5db5dc From: "9590206" ;tag=4vBe8B7SDN8SQ Call-ID: c5a934a7-6094-1237-1193-000db9478a88 CSeq: 130648330 INVITE Content-Length: 0 Proxy-Authenticate: Digest nonce="4E391DE4A093E85B00000000C8904334",realm="tel.t-online.de",algorithm=MD5,qop="auth",stale=true ------------------------------------------------------------------------ send 377 bytes to udp/[217.0.27.32]:5060 at 21:39:48.374475: ------------------------------------------------------------------------ ACK sip:08008080800@tel.t-online.de SIP/2.0 Via: SIP/2.0/UDP 172.19.50.3:5080;rport;branch=z9hG4bKjvmm45ygZaUcc Max-Forwards: 68 From: "9590206" ;tag=4vBe8B7SDN8SQ To: ;tag=h7g4Esbg_662a8891012f38ace0d410e96e5db5dc Call-ID: c5a934a7-6094-1237-1193-000db9478a88 CSeq: 130648330 ACK Content-Length: 0 ------------------------------------------------------------------------ send 1539 bytes to udp/[217.0.27.32]:5060 at 21:39:48.375770: ------------------------------------------------------------------------ INVITE sip:08008080800@tel.t-online.de SIP/2.0 Via: SIP/2.0/UDP 172.19.50.3:5080;rport;branch=z9hG4bKK5DD60FmvKHZQ Max-Forwards: 68 From: "9590206" ;tag=4vBe8B7SDN8SQ To: Call-ID: c5a934a7-6094-1237-1193-000db9478a88 CSeq: 130648331 INVITE Contact: User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Proxy-Authorization: Digest username="551124935083", realm="tel.t-online.de", nonce="4E391DE4A093E85B00000000C8904334", cnonce="xbs4KGCUEjeTEQANuUeKiA", algorithm=MD5, uri="sip:08008080800@tel.t-online.de", response="f1fa764442e0d8c357c9166be3d16313", qop=auth, nc=00000001 Content-Type: application/sdp Content-Disposition: session Content-Length: 381 P-Sig-Options: Overlap-Dialing X-FS-Support: update_display,send_info Remote-Party-ID: "9590206" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1541947070 1541947071 IN IP4 172.19.50.3 s=FreeSWITCH c=IN IP4 172.19.50.3 t=0 0 m=audio 21718 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:30 m=audio 21718 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 ------------------------------------------------------------------------ 2018-11-11 21:39:48.375669 [DEBUG] sofia.c:7291 Channel sofia/external/08008080800 entering state [calling][0] recv 317 bytes from udp/[217.0.27.32]:5060 at 21:39:48.588607: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.19.50.3:5080;received=172.19.50.3;rport=5080;branch=z9hG4bKK5DD60FmvKHZQ To: From: "9590206" ;tag=4vBe8B7SDN8SQ Call-ID: c5a934a7-6094-1237-1193-000db9478a88 CSeq: 130648331 INVITE Content-Length: 0 ------------------------------------------------------------------------ recv 847 bytes from udp/[217.0.27.32]:5060 at 21:39:48.629995: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 172.19.50.3:5080;received=172.19.50.3;rport=5080;branch=z9hG4bKK5DD60FmvKHZQ To: ;tag=h7g4Esbg_p65555t1541968788m476486c374126833s1_2514769627-1285358402 From: "9590206" ;tag=4vBe8B7SDN8SQ Call-ID: c5a934a7-6094-1237-1193-000db9478a88 CSeq: 130648331 INVITE Contact: Record-Route: P-Early-Media: sendonly Supported: timer Content-Type: application/sdp Content-Length: 207 Allow: UPDATE, PRACK, OPTIONS, BYE, ACK, CANCEL, INVITE, REGISTER v=0 o=- 1221829659 2514947857 IN IP4 0.0.0.0 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 0 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv ------------------------------------------------------------------------ 2018-11-11 21:39:48.615677 [DEBUG] sofia.c:7291 Channel sofia/external/08008080800 entering state [proceeding][183] 2018-11-11 21:39:48.615677 [DEBUG] sofia.c:7301 Remote SDP: v=0 o=- 1221829659 2514947857 IN IP4 0.0.0.0 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 0 RTP/AVP 8 101 2018-11-11 21:39:48.615677 [NOTICE] sofia.c:7304 Pre-Answer sofia/external/08008080800! 2018-11-11 21:39:48.635662 [DEBUG] switch_channel.c:3482 (sofia/external/08008080800) Callstate Change DOWN -> EARLY 2018-11-11 21:39:48.635662 [WARNING] switch_core_media.c:4877 RFC2543 from March 1999 called; They want their 0.0.0.0 hold method back..... 2018-11-11 21:39:48.635662 [NOTICE] sofia.c:7482 Hangup sofia/external/08008080800 [CS_CONSUME_MEDIA] [INCOMPATIBLE_DESTINATION] 2018-11-11 21:39:48.635662 [DEBUG] switch_ivr_originate.c:3941 Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION] 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08008080800) Running State Change CS_HANGUP (Cur 2 Tot 22) 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:847 (sofia/external/08008080800) Callstate Change EARLY -> HANGUP 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:849 (sofia/external/08008080800) State HANGUP 2018-11-11 21:39:48.635662 [DEBUG] mod_sofia.c:449 Channel sofia/external/08008080800 hanging up, cause: INCOMPATIBLE_DESTINATION 2018-11-11 21:39:48.635662 [DEBUG] mod_sofia.c:513 Sending CANCEL to sofia/external/08008080800 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:60 sofia/external/08008080800 Standard HANGUP, cause: INCOMPATIBLE_DESTINATION 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:849 (sofia/external/08008080800) State HANGUP going to sleep 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:619 (sofia/external/08008080800) State Change CS_HANGUP -> CS_REPORTING 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08008080800) Running State Change CS_REPORTING (Cur 2 Tot 22) 2018-11-11 21:39:48.635662 [INFO] mod_dptools.c:3518 Originate Failed. Cause: INCOMPATIBLE_DESTINATION send 393 bytes to udp/[217.0.27.32]:5060 at 21:39:48.639891: ------------------------------------------------------------------------ CANCEL sip:08008080800@tel.t-online.de SIP/2.0 Via: SIP/2.0/UDP 172.19.50.3:5080;rport;branch=z9hG4bKK5DD60FmvKHZQ Max-Forwards: 68 From: "9590206" ;tag=4vBe8B7SDN8SQ To: Call-ID: c5a934a7-6094-1237-1193-000db9478a88 CSeq: 130648331 CANCEL Reason: Q.850;cause=88;text="INCOMPATIBLE_DESTINATION" Content-Length: 0 ------------------------------------------------------------------------ 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:935 (sofia/external/08008080800) State REPORTING 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:174 sofia/external/08008080800 Standard REPORTING, cause: INCOMPATIBLE_DESTINATION 2018-11-11 21:39:48.635662 [NOTICE] switch_core_state_machine.c:385 sofia/internal/9590206@pbx.[anonym].net has executed the last dialplan instruction, hanging up. 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:935 (sofia/external/08008080800) State REPORTING going to sleep 2018-11-11 21:39:48.635662 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/internal/9590206@pbx.[anonym].net [CS_EXECUTE] [NORMAL_CLEARING] 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/9590206@pbx.[anonym].net) State EXECUTE going to sleep 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9590206@pbx.[anonym].net) Running State Change CS_HANGUP (Cur 2 Tot 22) 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:610 (sofia/external/08008080800) State Change CS_REPORTING -> CS_DESTROY 2018-11-11 21:39:48.635662 [DEBUG] switch_core_session.c:1714 Session 22 (sofia/external/08008080800) Locked, Waiting on external entities 2018-11-11 21:39:48.635662 [NOTICE] switch_core_session.c:1732 Session 22 (sofia/external/08008080800) Ended 2018-11-11 21:39:48.635662 [NOTICE] switch_core_session.c:1736 Close Channel sofia/external/08008080800 [CS_DESTROY] 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:847 (sofia/internal/9590206@pbx.[anonym].net) Callstate Change RINGING -> HANGUP 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:738 (sofia/external/08008080800) Running State Change CS_DESTROY (Cur 1 Tot 22) 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/9590206@pbx.[anonym].net) State HANGUP 2018-11-11 21:39:48.635662 [DEBUG] mod_sofia.c:449 Channel sofia/internal/9590206@pbx.[anonym].net hanging up, cause: NORMAL_CLEARING 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:748 (sofia/external/08008080800) State DESTROY 2018-11-11 21:39:48.635662 [DEBUG] mod_sofia.c:354 sofia/external/08008080800 SOFIA DESTROY 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:181 sofia/external/08008080800 Standard DESTROY 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:748 (sofia/external/08008080800) State DESTROY going to sleep 2018-11-11 21:39:48.635662 [DEBUG] mod_sofia.c:588 Responding to INVITE with: 480 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:60 sofia/internal/9590206@pbx.[anonym].net Standard HANGUP, cause: NORMAL_CLEARING 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/9590206@pbx.[anonym].net) State HANGUP going to sleep 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/9590206@pbx.[anonym].net) State Change CS_HANGUP -> CS_REPORTING 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9590206@pbx.[anonym].net) Running State Change CS_REPORTING (Cur 1 Tot 22) send 815 bytes to udp/[172.19.50.4]:3861 at 21:39:48.645438: ------------------------------------------------------------------------ SIP/2.0 480 Temporarily Unavailable Via: SIP/2.0/UDP 172.19.50.4:3861;branch=z9hG4bK-03B444AB;rport=3861 Max-Forwards: 69 From: ;tag=2770968075 To: ;tag=NaKZN7XSa5QKN Call-ID: 10d5c69393e85b01a048009033060682@410 CSeq: 1133815521 INVITE User-Agent: FreeSWITCH Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 P-Asserted-Identity: "08008080800" ------------------------------------------------------------------------ 2018-11-11 21:39:48.635662 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/9590206@pbx.[anonym].net) State REPORTING recv 687 bytes from udp/[172.19.50.4]:3861 at 21:39:48.648063: ------------------------------------------------------------------------ ACK sip:0108008080800@pbx.[anonym].net;user=phone SIP/2.0 Proxy-Authorization: Digest username="9590206",realm="pbx.[anonym].net",nonce="05c25e77-130a-4164-aae4-06486050c13a",response="5bc96013997736bfe9ae31f77fbf613e",uri="sip:0108008080800@pbx.[anonym].net;user=phone",qop=auth,cnonce="719b57f454db5b017ede009033060682",nc=00000001,algorithm=MD5 Via: SIP/2.0/UDP 172.19.50.4:3861;branch=z9hG4bK-03B444AB;rport From: ;tag=2770968075 To: ;tag=NaKZN7XSa5QKN Call-ID: 10d5c69393e85b01a048009033060682@410 CSeq: 1133815521 ACK Contact: Content-Length: 0 Max-Forwards: 70 ------------------------------------------------------------------------ recv 410 bytes from udp/[217.0.27.32]:5060 at 21:39:48.650984: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.19.50.3:5080;received=172.19.50.3;rport=5080;branch=z9hG4bKK5DD60FmvKHZQ To: ;tag=h7g4Esbg_p65555t1541968788m476486c374126833s1_2514769627-1285358402 From: "9590206" ;tag=4vBe8B7SDN8SQ Call-ID: c5a934a7-6094-1237-1193-000db9478a88 CSeq: 130648331 CANCEL P-Early-Media: sendonly Content-Length: 0 ------------------------------------------------------------------------ 2018-11-11 21:39:48.795699 [DEBUG] switch_core_state_machine.c:174 sofia/internal/9590206@pbx.[anonym].net Standard REPORTING, cause: NORMAL_CLEARING 2018-11-11 21:39:48.795699 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/9590206@pbx.[anonym].net) State REPORTING going to sleep 2018-11-11 21:39:48.795699 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/9590206@pbx.[anonym].net) State Change CS_REPORTING -> CS_DESTROY 2018-11-11 21:39:48.795699 [DEBUG] switch_core_session.c:1714 Session 21 (sofia/internal/9590206@pbx.[anonym].net) Locked, Waiting on external entities 2018-11-11 21:39:48.795699 [NOTICE] switch_core_session.c:1732 Session 21 (sofia/internal/9590206@pbx.[anonym].net) Ended 2018-11-11 21:39:48.795699 [NOTICE] switch_core_session.c:1736 Close Channel sofia/internal/9590206@pbx.[anonym].net [CS_DESTROY] 2018-11-11 21:39:48.795699 [DEBUG] switch_core_state_machine.c:738 (sofia/internal/9590206@pbx.[anonym].net) Running State Change CS_DESTROY (Cur 0 Tot 22) 2018-11-11 21:39:48.795699 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/9590206@pbx.[anonym].net) State DESTROY 2018-11-11 21:39:48.795699 [DEBUG] mod_sofia.c:354 sofia/internal/9590206@pbx.[anonym].net SOFIA DESTROY 2018-11-11 21:39:48.795699 [DEBUG] switch_core_state_machine.c:181 sofia/internal/9590206@pbx.[anonym].net Standard DESTROY 2018-11-11 21:39:48.795699 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/9590206@pbx.[anonym].net) State DESTROY going to sleep recv 467 bytes from udp/[217.0.27.32]:5060 at 21:39:53.702057: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 172.19.50.3:5080;received=172.19.50.3;rport=5080;branch=z9hG4bKK5DD60FmvKHZQ To: ;tag=h7g4Esbg_p65555t1541968788m476486c374126833s1_2514769627-1285358402 From: "9590206" ;tag=4vBe8B7SDN8SQ Call-ID: c5a934a7-6094-1237-1193-000db9478a88 CSeq: 130648331 INVITE Contact: Supported: timer Content-Length: 0 ------------------------------------------------------------------------ send 403 bytes to udp/[217.0.27.32]:5060 at 21:39:53.702670: ------------------------------------------------------------------------ ACK sip:08008080800@tel.t-online.de SIP/2.0 Via: SIP/2.0/UDP 172.19.50.3:5080;rport;branch=z9hG4bKK5DD60FmvKHZQ Max-Forwards: 68 From: "9590206" ;tag=4vBe8B7SDN8SQ To: ;tag=h7g4Esbg_p65555t1541968788m476486c374126833s1_2514769627-1285358402 Call-ID: c5a934a7-6094-1237-1193-000db9478a88 CSeq: 130648331 ACK Content-Length: 0