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: <sip:9590206@pbx.[anonym].net>;tag=2770968073
To: <sip:9590206@pbx.[anonym].net>
Call-ID: c7e2bd8b47e55b014639009033060682
CSeq: 3458 REGISTER
Contact: <sip:9590206@172.19.50.4:3861;transport=UDP>;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: <sip:9590206@pbx.[anonym].net>;tag=2770968073
To: <sip:9590206@pbx.[anonym].net>;tag=Kr0DjHvjgKBee
Call-ID: c7e2bd8b47e55b014639009033060682
CSeq: 3458 REGISTER
Contact: <sip:9590206@172.19.50.4:3861;transport=UDP>;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: <sip:11@pbx.[anonym].net>;tag=201447844
To: <sip:13@pbx.[anonym].net;user=phone>;tag=IVbQih4CEMYf
Call-ID: 6dc598b07ce85b01209e0090332616fc@4
CSeq: 2067 SUBSCRIBE
Contact: <sip:11@172.19.51.21:5060;transport=UDP>
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: <sip:11@pbx.[anonym].net>;tag=201447844
To: <sip:13@pbx.[anonym].net;user=phone>;tag=IVbQih4CEMYf
Call-ID: 6dc598b07ce85b01209e0090332616fc@4
CSeq: 2067 SUBSCRIBE
Contact: <sip:13@172.19.50.3:5060>
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: <sip:13@pbx.[anonym].net;user=phone>;tag=IVbQih4CEMYf
To: <sip:11@pbx.[anonym].net>;tag=201447844
Call-ID: 6dc598b07ce85b01209e0090332616fc@4
CSeq: 1360378251 NOTIFY
Contact: <sip:13@172.19.50.3:5060>
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
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="67" state="full" entity="sip:13@pbx.[anonym].net">
</dialog-info>
------------------------------------------------------------------------
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: <sip:13@pbx.[anonym].net;user=phone>;tag=IVbQih4CEMYf
To: <sip:11@pbx.[anonym].net>;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: <sip:11@pbx.[anonym].net>;tag=201447843
To: <sip:12@pbx.[anonym].net;user=phone>;tag=KwAnCbiD8uGu
Call-ID: e54e60b07ce85b011e9e0090332616fc@3
CSeq: 2067 SUBSCRIBE
Contact: <sip:11@172.19.51.21:5060;transport=UDP>
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: <sip:11@pbx.[anonym].net>;tag=201447843
To: <sip:12@pbx.[anonym].net;user=phone>;tag=KwAnCbiD8uGu
Call-ID: e54e60b07ce85b011e9e0090332616fc@3
CSeq: 2067 SUBSCRIBE
Contact: <sip:12@172.19.50.3:5060>
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: <sip:12@pbx.[anonym].net;user=phone>;tag=KwAnCbiD8uGu
To: <sip:11@pbx.[anonym].net>;tag=201447843
Call-ID: e54e60b07ce85b011e9e0090332616fc@3
CSeq: 1360378252 NOTIFY
Contact: <sip:12@172.19.50.3:5060>
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
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="71" state="full" entity="sip:12@pbx.[anonym].net">
</dialog-info>
------------------------------------------------------------------------
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: <sip:12@pbx.[anonym].net;user=phone>;tag=KwAnCbiD8uGu
To: <sip:11@pbx.[anonym].net>;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: <sip:9590206@pbx.[anonym].net>;tag=2770968075
To: <sip:0108008080800@pbx.[anonym].net;user=phone>
Call-ID: 10d5c69393e85b01a048009033060682@410
CSeq: 1133815520 INVITE
Contact: <sip:9590206@172.19.50.4:3861;transport=UDP>
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: <sip:%0631@pbx.[anonym].net;user=phone>
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: <sip:9590206@pbx.[anonym].net>;tag=2770968075
To: <sip:0108008080800@pbx.[anonym].net;user=phone>;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: <sip:9590206@pbx.[anonym].net>;tag=2770968075
To: <sip:0108008080800@pbx.[anonym].net;user=phone>;tag=m1S6KcDpDv10S
Call-ID: 10d5c69393e85b01a048009033060682@410
CSeq: 1133815520 ACK
Contact: <sip:9590206@172.19.50.4:3861;transport=UDP>
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: <sip:9590206@pbx.[anonym].net>;tag=2770968075
To: <sip:0108008080800@pbx.[anonym].net;user=phone>
Call-ID: 10d5c69393e85b01a048009033060682@410
CSeq: 1133815521 INVITE
Contact: <sip:9590206@172.19.50.4:3861;transport=UDP>
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: <sip:%0631@pbx.[anonym].net;user=phone>
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: <sip:9590206@pbx.[anonym].net>;tag=2770968075
To: <sip:0108008080800@pbx.[anonym].net;user=phone>
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" <sip:+49[anonym]206@tel.t-online.de>;tag=4vBe8B7SDN8SQ
To: <sip:08008080800@tel.t-online.de>
Call-ID: c5a934a7-6094-1237-1193-000db9478a88
CSeq: 130648330 INVITE
Contact: <sip:gw+737888c4-6119-4b50-9b6d-176732c5fb2d@172.19.50.3:5080;transport=udp;gw=737888c4-6119-4b50-9b6d-176732c5fb2d>
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" <sip: 31@tel.t-online.de>;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: <sip:08008080800@tel.t-online.de>;tag=h7g4Esbg_662a8891012f38ace0d410e96e5db5dc
From: "9590206" <sip:+49[anonym]206@tel.t-online.de>;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" <sip:+49[anonym]206@tel.t-online.de>;tag=4vBe8B7SDN8SQ
To: <sip:08008080800@tel.t-online.de>;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" <sip:+49[anonym]206@tel.t-online.de>;tag=4vBe8B7SDN8SQ
To: <sip:08008080800@tel.t-online.de>
Call-ID: c5a934a7-6094-1237-1193-000db9478a88
CSeq: 130648331 INVITE
Contact: <sip:gw+737888c4-6119-4b50-9b6d-176732c5fb2d@172.19.50.3:5080;transport=udp;gw=737888c4-6119-4b50-9b6d-176732c5fb2d>
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" <sip: 31@tel.t-online.de>;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: <sip:08008080800@tel.t-online.de>
From: "9590206" <sip:+49[anonym]206@tel.t-online.de>;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: <sip:08008080800@tel.t-online.de>;tag=h7g4Esbg_p65555t1541968788m476486c374126833s1_2514769627-1285358402
From: "9590206" <sip:+49[anonym]206@tel.t-online.de>;tag=4vBe8B7SDN8SQ
Call-ID: c5a934a7-6094-1237-1193-000db9478a88
CSeq: 130648331 INVITE
Contact: <sip:sgc_c@217.0.27.32;transport=udp>
Record-Route: <sip:217.0.27.32;transport=udp;lr>
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" <sip:+49[anonym]206@tel.t-online.de>;tag=4vBe8B7SDN8SQ
To: <sip:08008080800@tel.t-online.de>
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: <sip:9590206@pbx.[anonym].net>;tag=2770968075
To: <sip:0108008080800@pbx.[anonym].net;user=phone>;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" <sip:08008080800@pbx.[anonym].net>
------------------------------------------------------------------------
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: <sip:9590206@pbx.[anonym].net>;tag=2770968075
To: <sip:0108008080800@pbx.[anonym].net;user=phone>;tag=NaKZN7XSa5QKN
Call-ID: 10d5c69393e85b01a048009033060682@410
CSeq: 1133815521 ACK
Contact: <sip:9590206@172.19.50.4:3861;transport=UDP>
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: <sip:08008080800@tel.t-online.de>;tag=h7g4Esbg_p65555t1541968788m476486c374126833s1_2514769627-1285358402
From: "9590206" <sip:+49[anonym]206@tel.t-online.de>;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: <sip:08008080800@tel.t-online.de>;tag=h7g4Esbg_p65555t1541968788m476486c374126833s1_2514769627-1285358402
From: "9590206" <sip:+49[anonym]206@tel.t-online.de>;tag=4vBe8B7SDN8SQ
Call-ID: c5a934a7-6094-1237-1193-000db9478a88
CSeq: 130648331 INVITE
Contact: <sip:sgc_c@217.0.27.32;transport=udp>
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" <sip:+49[anonym]206@tel.t-online.de>;tag=4vBe8B7SDN8SQ
To: <sip:08008080800@tel.t-online.de>;tag=h7g4Esbg_p65555t1541968788m476486c374126833s1_2514769627-1285358402
Call-ID: c5a934a7-6094-1237-1193-000db9478a88
CSeq: 130648331 ACK
Content-Length: 0