INVITE sip:100@192.168.10.242 SIP/2.0
Via: SIP/2.0/TCP 192.168.10.43:57549;branch=z9hG4bK-524287-1---1e2e046781e24f 50;rport
Max-Forwards: 70
Contact: <sip:101@192.168.10.43:57580;rinstance=7e36b9c365f6f298;transport=tc p>
To: <sip:100@192.168.10.242>
From: "101"<sip:101@192.168.10.242>;tag=8d508257
Call-ID: 89322Mjg2YTQyYjcyMWE3ZjY4YTQ2MWRkMTBmMDQ3YTkzM2I
CSeq: 1 INVITE
Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MES SAGE
Content-Type: application/sdp
Supported: replaces
User-Agent: X-Lite release 5.1.0 stamp 89322
Content-Length: 336
v=0
o=- 13164672648080945 1 IN IP4 192.168.10.43
s=X-Lite release 5.1.0 stamp 89322
c=IN IP4 192.168.10.43
t=0 0
m=audio 54270 RTP/AVP 9 8 120 0 84 101
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
------------------------------------------------------------------------
2018-03-04 23:30:46.002858 [NOTICE] switch_channel.c:1104 New Channel sofia/inte rnal/101@192.168.10.242 [e1512308-b4d6-42de-a1cc-4ff4c31ed8ca]
2018-03-04 23:30:46.002858 [DEBUG] switch_core_state_machine.c:584 (sofia/intern al/101@192.168.10.242) Running State Change CS_NEW (Cur 1 Tot 4)
2018-03-04 23:30:46.002858 [DEBUG] sofia.c:10070 sofia/internal/101@192.168.10.2 42 receiving invite from 192.168.10.43:57580 version: 1.6.19 64bit
2018-03-04 23:30:46.002858 [DEBUG] sofia.c:10186 IP 192.168.10.43 Approved by ac l "domains[]". Access Granted.
2018-03-04 23:30:46.002858 [DEBUG] sofia.c:11378 Setting NAT mode based on via p ort
2018-03-04 23:30:46.002858 [DEBUG] sofia.c:7283 Channel sofia/internal/101@192.1 68.10.242 entering state [received][100]
2018-03-04 23:30:46.002858 [DEBUG] sofia.c:7293 Remote SDP:
v=0
o=- 13164672648080945 1 IN IP4 192.168.10.43
s=X-Lite release 5.1.0 stamp 89322
c=IN IP4 192.168.10.43
t=0 0
m=audio 54270 RTP/AVP 9 8 120 0 84 101
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:84 speex/16000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5129 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5129 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5129 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5129 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5184 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5129 Audio Codec Compare [opus:120:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5129 Audio Codec Compare [opus:120:48000:20:0:2]/[PCMA:8:8000:20:64000:1]
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5129 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5184 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5129 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5129 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5129 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5045 Set telephone-event payload to 101@8000
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:3444 Set Codec sofia/inte rnal/101@192.168.10.242 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2018-03-04 23:30:46.002858 [DEBUG] switch_core_codec.c:111 sofia/internal/101@19 2.168.10.242 Original read codec set to PCMA:8
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5388 Set telephone-event payload to 101@8000
2018-03-04 23:30:46.002858 [DEBUG] switch_core_media.c:5446 sofia/internal/101@1 92.168.10.242 Set 2833 dtmf send payload to 101 recv payload to 101
2018-03-04 23:30:46.002858 [DEBUG] sofia.c:7706 (sofia/internal/101@192.168.10.2 42) State Change CS_NEW -> CS_INIT
2018-03-04 23:30:46.002858 [DEBUG] switch_core_state_machine.c:603 (sofia/intern al/101@192.168.10.242) State NEW
2018-03-04 23:30:46.002858 [DEBUG] switch_core_state_machine.c:584 (sofia/intern al/101@192.168.10.242) Running State Change CS_INIT (Cur 1 Tot 4)
2018-03-04 23:30:46.002858 [DEBUG] switch_core_state_machine.c:627 (sofia/intern al/101@192.168.10.242) State INIT
2018-03-04 23:30:46.002858 [DEBUG] mod_sofia.c:93 sofia/internal/101@192.168.10. 242 SOFIA INIT
2018-03-04 23:30:46.002858 [DEBUG] switch_core_state_machine.c:40 sofia/internal /101@192.168.10.242 Standard INIT
2018-03-04 23:30:46.002858 [DEBUG] switch_core_state_machine.c:48 (sofia/interna l/101@192.168.10.242) State Change CS_INIT -> CS_ROUTING
2018-03-04 23:30:46.002858 [DEBUG] switch_core_state_machine.c:627 (sofia/intern al/101@192.168.10.242) State INIT going to sleep
2018-03-04 23:30:46.002858 [DEBUG] switch_core_state_machine.c:584 (sofia/intern al/101@192.168.10.242) Running State Change CS_ROUTING (Cur 1 Tot 4)
2018-03-04 23:30:46.002858 [DEBUG] switch_channel.c:2249 (sofia/internal/101@192 .168.10.242) Callstate Change DOWN -> RINGING
2018-03-04 23:30:46.002858 [DEBUG] switch_core_state_machine.c:643 (sofia/intern al/101@192.168.10.242) State ROUTING
2018-03-04 23:30:46.002858 [DEBUG] mod_sofia.c:154 sofia/internal/101@192.168.10 .242 SOFIA ROUTING
2018-03-04 23:30:46.002858 [DEBUG] switch_core_state_machine.c:236 sofia/interna l/101@192.168.10.242 Standard ROUTING
2018-03-04 23:30:46.002858 [INFO] mod_dialplan_xml.c:637 Processing 101 <101>->1 00 in context public
send 313 bytes to tcp/[192.168.10.43]:57580 at 23:30:46.241319:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 192.168.10.43:57549;branch=z9hG4bK-524287-1---1e2e046781e24f 50;rport=57580
From: "101"<sip:101@192.168.10.242>;tag=8d508257
To: <sip:100@192.168.10.242>
Call-ID: 89322Mjg2YTQyYjcyMWE3ZjY4YTQ2MWRkMTBmMDQ3YTkzM2I
CSeq: 1 INVITE
User-Agent: FreeSWITCH
Content-Length: 0
------------------------------------------------------------------------
Dialplan: sofia/internal/101@192.168.10.242 parsing [public->caller-details] con tinue=true
Dialplan: sofia/internal/101@192.168.10.242 Regex (PASS) [caller-details] () =~ // break=never
Dialplan: sofia/internal/101@192.168.10.242 Action export(call_direction=inbound ) INLINE
EXECUTE sofia/internal/101@192.168.10.242 export(call_direction=inbound)
2018-03-04 23:30:46.002858 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [c all_direction]=[inbound]
Dialplan: sofia/internal/101@192.168.10.242 Action set(caller_destination=${dest ination_number}) INLINE
EXECUTE sofia/internal/101@192.168.10.242 set(caller_destination=100)
2018-03-04 23:30:46.022856 [DEBUG] mod_dptools.c:1588 SET sofia/internal/101@192 .168.10.242 [caller_destination]=[100]
Dialplan: sofia/internal/101@192.168.10.242 Action set(caller_id_name=${caller_i d_name}) INLINE
EXECUTE sofia/internal/101@192.168.10.242 set(caller_id_name=101)
2018-03-04 23:30:46.022856 [DEBUG] mod_dptools.c:1588 SET sofia/internal/101@192 .168.10.242 [caller_id_name]=[101]
Dialplan: sofia/internal/101@192.168.10.242 Action set(caller_id_number=${caller _id_number}) INLINE
EXECUTE sofia/internal/101@192.168.10.242 set(caller_id_number=101)
2018-03-04 23:30:46.022856 [DEBUG] mod_dptools.c:1588 SET sofia/internal/101@192 .168.10.242 [caller_id_number]=[101]
Dialplan: sofia/internal/101@192.168.10.242 parsing [public->not-found] continue =false
Dialplan: sofia/internal/101@192.168.10.242 Regex (PASS) [not-found] () =~ // br eak=on-false
Dialplan: sofia/internal/101@192.168.10.242 Action export(call_direction=inbound ) INLINE
EXECUTE sofia/internal/101@192.168.10.242 export(call_direction=inbound)
2018-03-04 23:30:46.022856 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [c all_direction]=[inbound]
Dialplan: sofia/internal/101@192.168.10.242 Action set(call_direction=inbound) I NLINE
EXECUTE sofia/internal/101@192.168.10.242 set(call_direction=inbound)
2018-03-04 23:30:46.022856 [DEBUG] mod_dptools.c:1588 SET sofia/internal/101@192 .168.10.242 [call_direction]=[inbound]
Dialplan: sofia/internal/101@192.168.10.242 Action log([inbound routes] 404 not found ${sip_network_ip}) INLINE
EXECUTE sofia/internal/101@192.168.10.242 log([inbound routes] 404 not found 192 .168.10.43)
2018-03-04 23:30:46.022856 [DEBUG] mod_dptools.c:1782 routes] 404 not found 192. 168.10.43
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:286 (sofia/intern al/101@192.168.10.242) State Change CS_ROUTING -> CS_EXECUTE
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:643 (sofia/intern al/101@192.168.10.242) State ROUTING going to sleep
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:584 (sofia/intern al/101@192.168.10.242) Running State Change CS_EXECUTE (Cur 1 Tot 4)
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:650 (sofia/intern al/101@192.168.10.242) State EXECUTE
2018-03-04 23:30:46.022856 [DEBUG] mod_sofia.c:209 sofia/internal/101@192.168.10 .242 SOFIA EXECUTE
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:328 sofia/interna l/101@192.168.10.242 Standard EXECUTE
2018-03-04 23:30:46.022856 [NOTICE] switch_core_state_machine.c:385 sofia/intern al/101@192.168.10.242 has executed the last dialplan instruction, hanging up.
2018-03-04 23:30:46.022856 [NOTICE] switch_core_state_machine.c:387 Hangup sofia /internal/101@192.168.10.242 [CS_EXECUTE] [NORMAL_CLEARING]
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:650 (sofia/intern al/101@192.168.10.242) State EXECUTE going to sleep
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:584 (sofia/intern al/101@192.168.10.242) Running State Change CS_HANGUP (Cur 1 Tot 4)
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:850 (sofia/intern al/101@192.168.10.242) Callstate Change RINGING -> HANGUP
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:852 (sofia/intern al/101@192.168.10.242) State HANGUP
2018-03-04 23:30:46.022856 [DEBUG] mod_sofia.c:449 Channel sofia/internal/101@19 2.168.10.242 hanging up, cause: NORMAL_CLEARING
2018-03-04 23:30:46.022856 [DEBUG] mod_sofia.c:588 Responding to INVITE with: 48 0
send 838 bytes to tcp/[192.168.10.43]:57580 at 23:30:46.248855:
------------------------------------------------------------------------
SIP/2.0 480 Temporarily Unavailable
Via: SIP/2.0/TCP 192.168.10.43:57549;branch=z9hG4bK-524287-1---1e2e046781e24f 50;rport=57580
Max-Forwards: 70
From: "101"<sip:101@192.168.10.242>;tag=8d508257
To: <sip:100@192.168.10.242>;tag=H115Qr0Xec41S
Call-ID: 89322Mjg2YTQyYjcyMWE3ZjY4YTQ2MWRkMTBmMDQ3YTkzM2I
CSeq: 1 INVITE
User-Agent: FreeSWITCH
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, RE FER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, lin e-seize, call-info, sla, include-session-description, presence.winfo, message-su mmary, refer
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
Remote-Party-ID: "100" <sip:100@192.168.10.242>;party=calling;privacy=off;scr een=no
------------------------------------------------------------------------
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:60 sofia/internal /101@192.168.10.242 Standard HANGUP, cause: NORMAL_CLEARING
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:852 (sofia/intern al/101@192.168.10.242) State HANGUP going to sleep
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:619 (sofia/intern al/101@192.168.10.242) State Change CS_HANGUP -> CS_REPORTING
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:584 (sofia/intern al/101@192.168.10.242) Running State Change CS_REPORTING (Cur 1 Tot 4)
2018-03-04 23:30:46.022856 [DEBUG] switch_core_state_machine.c:938 (sofia/intern al/101@192.168.10.242) State REPORTING
recv 332 bytes from tcp/[192.168.10.43]:57580 at 23:30:46.281825:
------------------------------------------------------------------------
ACK sip:100@192.168.10.242 SIP/2.0
Via: SIP/2.0/TCP 192.168.10.43:57549;branch=z9hG4bK-524287-1---1e2e046781e24f 50;rport
Max-Forwards: 70
To: <sip:100@192.168.10.242>;tag=H115Qr0Xec41S
From: "101"<sip:101@192.168.10.242>;tag=8d508257
Call-ID: 89322Mjg2YTQyYjcyMWE3ZjY4YTQ2MWRkMTBmMDQ3YTkzM2I
CSeq: 1 ACK
Content-Length: 0
------------------------------------------------------------------------
2018-03-04 23:30:46.102853 [DEBUG] switch_core_state_machine.c:174 sofia/interna l/101@192.168.10.242 Standard REPORTING, cause: NORMAL_CLEARING
2018-03-04 23:30:46.102853 [DEBUG] switch_core_state_machine.c:938 (sofia/intern al/101@192.168.10.242) State REPORTING going to sleep
2018-03-04 23:30:46.102853 [DEBUG] switch_core_state_machine.c:610 (sofia/intern al/101@192.168.10.242) State Change CS_REPORTING -> CS_DESTROY
2018-03-04 23:30:46.102853 [DEBUG] switch_core_session.c:1713 Session 4 (sofia/i nternal/101@192.168.10.242) Locked, Waiting on external entities
2018-03-04 23:30:46.102853 [NOTICE] switch_core_session.c:1731 Session 4 (sofia/ internal/101@192.168.10.242) Ended
2018-03-04 23:30:46.102853 [NOTICE] switch_core_session.c:1735 Close Channel sof ia/internal/101@192.168.10.242 [CS_DESTROY]
2018-03-04 23:30:46.102853 [DEBUG] switch_core_state_machine.c:741 (sofia/intern al/101@192.168.10.242) Running State Change CS_DESTROY (Cur 0 Tot 4)
2018-03-04 23:30:46.102853 [DEBUG] switch_core_state_machine.c:751 (sofia/intern al/101@192.168.10.242) State DESTROY
2018-03-04 23:30:46.102853 [DEBUG] mod_sofia.c:354 sofia/internal/101@192.168.10 .242 SOFIA DESTROY
2018-03-04 23:30:46.102853 [DEBUG] switch_core_state_machine.c:181 sofia/interna l/101@192.168.10.242 Standard DESTROY
2018-03-04 23:30:46.102853 [DEBUG] switch_core_state_machine.c:751 (sofia/intern al/101@192.168.10.242) State DESTROY going to sleep