[m[33m[44m.=======================================================. | _____ ____ ____ _ ___ | | | ___/ ___| / ___| | |_ _| | | | |_ \___ \ | | | | | | | | | _| ___) | | |___| |___ | | | | |_| |____/ \____|_____|___| | | | .=======================================================. | Anthony Minessale II, Ken Rice, | | Michael Jerris, Travis Cross | | FreeSWITCH (http://www.freeswitch.org) | | Paypal Donations Appreciated: paypal@freeswitch.org | | Brought to you by ClueCon http://www.cluecon.com/ | .=======================================================. .===============================================================. | _ | | ___| |_ _ ___ ___ ___ _ __ ___ ___ _ __ ___ | | / __| | | | |/ _ \/ __/ _ \| '_ \ / __/ _ \| '_ ` _ \ | | | (__| | |_| | __/ (_| (_) | | | | _ | (_| (_) | | | | | | | | \___|_|\__,_|\___|\___\___/|_| |_| (_) \___\___/|_| |_| |_| | | | .===============================================================. [m Type /help to see a list of commands [m [This app Best viewed at 160x60 or more..] +OK log level 7 [7] freeswitch@internal> Enabled sip debugging on internal freeswitch@internal> 2018-11-26 18:16:18.143827 [NOTICE] switch_channel.c:1077 New Channel sofia/external/8005@59.110.40.211 [0c690a7c-5b32-4328-b3f4-c5a5fc00ce72] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:1062 Send signal sofia/external/8005@59.110.40.211 [BREAK] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:1062 Send signal sofia/external/8005@59.110.40.211 [BREAK] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:472 (sofia/external/8005@59.110.40.211) Running State Change CS_NEW 2018-11-26 18:16:18.143827 [DEBUG] sofia.c:8957 sofia/external/8005@59.110.40.211 receiving invite from 185.107.83.45:64371 version: 1.4.26 64bit 2018-11-26 18:16:18.143827 [DEBUG] sofia.c:6658 Channel sofia/external/8005@59.110.40.211 entering state [received][100] 2018-11-26 18:16:18.143827 [DEBUG] sofia.c:6668 Remote SDP: v=0 o=8005 16264 18299 IN IP4 192.168.1.83 s=call c=IN IP4 192.168.1.83 t=0 0 m=audio 25282 RTP/AVP 0 101 a=rtpmap:0 pcmu/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 2018-11-26 18:16:18.143827 [DEBUG] sofia.c:6934 (sofia/external/8005@59.110.40.211) State Change CS_NEW -> CS_INIT 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/8005@59.110.40.211 [BREAK] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:491 (sofia/external/8005@59.110.40.211) State NEW 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:472 (sofia/external/8005@59.110.40.211) Running State Change CS_INIT 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:512 (sofia/external/8005@59.110.40.211) State INIT 2018-11-26 18:16:18.143827 [DEBUG] mod_sofia.c:87 sofia/external/8005@59.110.40.211 SOFIA INIT 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:40 sofia/external/8005@59.110.40.211 Standard INIT 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:48 (sofia/external/8005@59.110.40.211) State Change CS_INIT -> CS_ROUTING 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/8005@59.110.40.211 [BREAK] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:512 (sofia/external/8005@59.110.40.211) State INIT going to sleep 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:472 (sofia/external/8005@59.110.40.211) Running State Change CS_ROUTING 2018-11-26 18:16:18.143827 [DEBUG] switch_channel.c:2206 (sofia/external/8005@59.110.40.211) Callstate Change DOWN -> RINGING 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:528 (sofia/external/8005@59.110.40.211) State ROUTING 2018-11-26 18:16:18.143827 [DEBUG] mod_sofia.c:123 sofia/external/8005@59.110.40.211 SOFIA ROUTING 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:166 sofia/external/8005@59.110.40.211 Standard ROUTING 2018-11-26 18:16:18.143827 [INFO] mod_dialplan_xml.c:635 Processing 8005 <8005>->1668600972567135732 in context public Dialplan: sofia/external/8005@59.110.40.211 parsing [public->public_did1] continue=false Dialplan: sofia/external/8005@59.110.40.211 Regex (FAIL) [public_did1] destination_number(1668600972567135732) =~ /service/ break=on-false Dialplan: sofia/external/8005@59.110.40.211 parsing [public->public_did1] continue=false Dialplan: sofia/external/8005@59.110.40.211 Regex (PASS) [public_did1] destination_number(1668600972567135732) =~ /(\d+)$/ break=on-false Dialplan: sofia/external/8005@59.110.40.211 Action info() Dialplan: sofia/external/8005@59.110.40.211 Action set(domain_name=172.17.122.132) Dialplan: sofia/external/8005@59.110.40.211 Action set(callType=inbound) Dialplan: sofia/external/8005@59.110.40.211 Action set(dtmf_type=inband) Dialplan: sofia/external/8005@59.110.40.211 Action start_dtmf() Dialplan: sofia/external/8005@59.110.40.211 Action socket(127.0.0.1:9021 async full) 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:216 (sofia/external/8005@59.110.40.211) State Change CS_ROUTING -> CS_EXECUTE 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/8005@59.110.40.211 [BREAK] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:528 (sofia/external/8005@59.110.40.211) State ROUTING going to sleep 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:472 (sofia/external/8005@59.110.40.211) Running State Change CS_EXECUTE 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:535 (sofia/external/8005@59.110.40.211) State EXECUTE 2018-11-26 18:16:18.143827 [DEBUG] mod_sofia.c:178 sofia/external/8005@59.110.40.211 SOFIA EXECUTE 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:258 sofia/external/8005@59.110.40.211 Standard EXECUTE EXECUTE sofia/external/8005@59.110.40.211 info() 2018-11-26 18:16:18.143827 [INFO] mod_dptools.c:1689 CHANNEL_DATA: Channel-State: [CS_EXECUTE] Channel-Call-State: [RINGING] Channel-State-Number: [4] Channel-Name: [sofia/external/8005@59.110.40.211] Unique-ID: [0c690a7c-5b32-4328-b3f4-c5a5fc00ce72] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-HIT-Dialplan: [true] Channel-Call-UUID: [0c690a7c-5b32-4328-b3f4-c5a5fc00ce72] Answer-State: [ringing] Caller-Direction: [inbound] Caller-Logical-Direction: [inbound] Caller-Username: [8005] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [8005] Caller-Caller-ID-Number: [8005] Caller-Orig-Caller-ID-Name: [8005] Caller-Orig-Caller-ID-Number: [8005] Caller-Network-Addr: [185.107.83.45] Caller-ANI: [8005] Caller-Destination-Number: [1668600972567135732] Caller-Unique-ID: [0c690a7c-5b32-4328-b3f4-c5a5fc00ce72] Caller-Source: [mod_sofia] Caller-Context: [public] Caller-Channel-Name: [sofia/external/8005@59.110.40.211] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1543227378143827] Caller-Channel-Created-Time: [1543227378143827] Caller-Channel-Answered-Time: [0] Caller-Channel-Progress-Time: [0] Caller-Channel-Progress-Media-Time: [0] Caller-Channel-Hangup-Time: [0] Caller-Channel-Transfer-Time: [0] Caller-Channel-Resurrect-Time: [0] Caller-Channel-Bridged-Time: [0] Caller-Channel-Last-Hold: [0] Caller-Channel-Hold-Accum: [0] Caller-Screen-Bit: [true] Caller-Privacy-Hide-Name: [false] Caller-Privacy-Hide-Number: [false] variable_direction: [inbound] variable_uuid: [0c690a7c-5b32-4328-b3f4-c5a5fc00ce72] variable_session_id: [359] variable_sip_from_user: [8005] variable_sip_from_uri: [8005@59.110.40.211] variable_sip_from_host: [59.110.40.211] variable_channel_name: [sofia/external/8005@59.110.40.211] variable_sip_call_id: [1974395535-1484735412-2132000161] variable_ep_codec_string: [pcmu@8000h@20i@64000b] variable_sip_local_network_addr: [59.110.40.211] variable_sip_network_ip: [185.107.83.45] variable_sip_network_port: [64371] variable_sip_received_ip: [185.107.83.45] variable_sip_received_port: [64371] variable_sip_via_protocol: [udp] variable_sip_from_user_stripped: [8005] variable_sip_from_tag: [1754981914] variable_sofia_profile_name: [external] variable_recovery_profile_name: [external] variable_sip_full_via: [SIP/2.0/UDP 185.107.83.45:64371;branch=z9hG4bK8604400] variable_sip_full_from: [;tag=1754981914] variable_sip_full_to: [] variable_sip_req_user: [1668600972567135732] variable_sip_req_uri: [1668600972567135732@59.110.40.211] variable_sip_req_host: [59.110.40.211] variable_sip_to_user: [1668600972567135732] variable_sip_to_uri: [1668600972567135732@59.110.40.211] variable_sip_to_host: [59.110.40.211] variable_sip_contact_user: [8005] variable_sip_contact_port: [64371] variable_sip_contact_uri: [8005@185.107.83.45:64371] variable_sip_contact_host: [185.107.83.45] variable_rtp_use_codec_string: [G729,OPUS,PCMU,PCMA] variable_sip_user_agent: [zxcvfdf11] variable_sip_via_host: [185.107.83.45] variable_sip_via_port: [64371] variable_max_forwards: [70] variable_switch_r_sdp: [v=0 o=8005 16264 18299 IN IP4 192.168.1.83 s=call c=IN IP4 192.168.1.83 t=0 0 m=audio 25282 RTP/AVP 0 101 a=rtpmap:0 pcmu/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 ] variable_endpoint_disposition: [DELAYED NEGOTIATION] variable_DP_MATCH: [ARRAY::1668600972567135732|:1668600972567135732] variable_call_uuid: [0c690a7c-5b32-4328-b3f4-c5a5fc00ce72] variable_current_application: [info] EXECUTE sofia/external/8005@59.110.40.211 set(domain_name=172.17.122.132) 2018-11-26 18:16:18.143827 [DEBUG] mod_dptools.c:1477 sofia/external/8005@59.110.40.211 SET [domain_name]=[172.17.122.132] EXECUTE sofia/external/8005@59.110.40.211 set(callType=inbound) 2018-11-26 18:16:18.143827 [DEBUG] mod_dptools.c:1477 sofia/external/8005@59.110.40.211 SET [callType]=[inbound] EXECUTE sofia/external/8005@59.110.40.211 set(dtmf_type=inband) 2018-11-26 18:16:18.143827 [DEBUG] mod_dptools.c:1477 sofia/external/8005@59.110.40.211 SET [dtmf_type]=[inband] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:2599 Application start_dtmf Requires media! pre_answering channel sofia/external/8005@59.110.40.211 2018-11-26 18:16:18.143827 [INFO] switch_core_session.c:2601 Sending early media 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [pcmu:0:8000:20:64000:1]/[G729:18:8000:20:8000:1] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [pcmu:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [pcmu:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [pcmu:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:3595 Set telephone-event payload to 101 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:2506 Set Codec sofia/external/8005@59.110.40.211 PCMU/8000 20 ms 160 samples 64000 bits 1 channels 2018-11-26 18:16:18.143827 [DEBUG] switch_core_codec.c:111 sofia/external/8005@59.110.40.211 Original read codec set to PCMU:0 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:3942 Set 2833 dtmf send/recv payload to 101 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:5178 AUDIO RTP [sofia/external/8005@59.110.40.211] 172.17.122.132 port 24322 -> 192.168.1.83 port 25282 codec: 0 ms: 20 2018-11-26 18:16:18.143827 [DEBUG] switch_rtp.c:3608 Starting timer [soft] 160 bytes per 20ms 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:5476 Set 2833 dtmf send payload to 101 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:5482 Set 2833 dtmf receive payload to 101 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media.c:5504 sofia/external/8005@59.110.40.211 Set rtp dtmf delay to 40 2018-11-26 18:16:18.143827 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/8005@59.110.40.211! 2018-11-26 18:16:18.143827 [DEBUG] switch_channel.c:3421 (sofia/external/8005@59.110.40.211) Callstate Change RINGING -> EARLY 2018-11-26 18:16:18.143827 [DEBUG] mod_sofia.c:2264 Ring SDP: v=0 o=FreeSWITCH 1543203056 1543203057 IN IP4 59.110.40.211 s=FreeSWITCH c=IN IP4 59.110.40.211 t=0 0 m=audio 24322 RTP/AVP 0 101 a=rtpmap:0 pcmu/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:913 Send signal sofia/external/8005@59.110.40.211 [BREAK] EXECUTE sofia/external/8005@59.110.40.211 start_dtmf() 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media_bug.c:519 Attaching BUG to sofia/external/8005@59.110.40.211 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:1062 Send signal sofia/external/8005@59.110.40.211 [BREAK] 2018-11-26 18:16:18.143827 [DEBUG] sofia.c:6658 Channel sofia/external/8005@59.110.40.211 entering state [early][183] EXECUTE sofia/external/8005@59.110.40.211 socket(127.0.0.1:9021 async full) 2018-11-26 18:16:18.143827 [ERR] mod_event_socket.c:454 Socket Error! 2018-11-26 18:16:18.143827 [NOTICE] switch_core_state_machine.c:315 sofia/external/8005@59.110.40.211 has executed the last dialplan instruction, hanging up. 2018-11-26 18:16:18.143827 [NOTICE] switch_core_state_machine.c:317 Hangup sofia/external/8005@59.110.40.211 [CS_EXECUTE] [NORMAL_CLEARING] 2018-11-26 18:16:18.143827 [DEBUG] switch_channel.c:3244 Send signal sofia/external/8005@59.110.40.211 [KILL] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/8005@59.110.40.211 [BREAK] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:535 (sofia/external/8005@59.110.40.211) State EXECUTE going to sleep 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:472 (sofia/external/8005@59.110.40.211) Running State Change CS_HANGUP 2018-11-26 18:16:18.143827 [DEBUG] switch_core_media_bug.c:775 Removing BUG from sofia/external/8005@59.110.40.211 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:735 (sofia/external/8005@59.110.40.211) Callstate Change EARLY -> HANGUP 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:737 (sofia/external/8005@59.110.40.211) State HANGUP 2018-11-26 18:16:18.143827 [DEBUG] mod_sofia.c:413 Channel sofia/external/8005@59.110.40.211 hanging up, cause: NORMAL_CLEARING 2018-11-26 18:16:18.143827 [DEBUG] mod_sofia.c:549 Responding to INVITE with: 480 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:60 sofia/external/8005@59.110.40.211 Standard HANGUP, cause: NORMAL_CLEARING 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:737 (sofia/external/8005@59.110.40.211) State HANGUP going to sleep 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:504 (sofia/external/8005@59.110.40.211) State Change CS_HANGUP -> CS_REPORTING 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/8005@59.110.40.211 [BREAK] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:472 (sofia/external/8005@59.110.40.211) Running State Change CS_REPORTING 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:823 (sofia/external/8005@59.110.40.211) State REPORTING 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:104 sofia/external/8005@59.110.40.211 Standard REPORTING, cause: NORMAL_CLEARING 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:823 (sofia/external/8005@59.110.40.211) State REPORTING going to sleep 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:498 (sofia/external/8005@59.110.40.211) State Change CS_REPORTING -> CS_DESTROY 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/8005@59.110.40.211 [BREAK] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_session.c:1624 Session 359 (sofia/external/8005@59.110.40.211) Locked, Waiting on external entities 2018-11-26 18:16:18.143827 [NOTICE] switch_core_session.c:1642 Session 359 (sofia/external/8005@59.110.40.211) Ended 2018-11-26 18:16:18.143827 [NOTICE] switch_core_session.c:1646 Close Channel sofia/external/8005@59.110.40.211 [CS_DESTROY] 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:626 (sofia/external/8005@59.110.40.211) Running State Change CS_DESTROY 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:636 (sofia/external/8005@59.110.40.211) State DESTROY 2018-11-26 18:16:18.143827 [DEBUG] mod_sofia.c:323 sofia/external/8005@59.110.40.211 SOFIA DESTROY 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:111 sofia/external/8005@59.110.40.211 Standard DESTROY 2018-11-26 18:16:18.143827 [DEBUG] switch_core_state_machine.c:636 (sofia/external/8005@59.110.40.211) State DESTROY going to sleep 2018-11-26 18:16:21.703825 [NOTICE] sofia_reg.c:448 Registering 01088881234 2018-11-26 18:16:21.723823 [ERR] sofia_reg.c:2392 01088881234 Failed Registration with status Service Unavailable [503]. failure #735 2018-11-26 18:16:22.703826 [WARNING] sofia_reg.c:505 01088881234 Failed Registration [503], setting retry to 30 seconds.