[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@cpe003> Enabled sip debugging on internal freeswitch@cpe003> UP 0 years, 0 days, 0 hours, 22 minutes, 21 seconds, 202 milliseconds, 122 microseconds FreeSWITCH (Version 1.6.19 git b1b21d0 2017-11-20 16:34:16Z 64bit) is ready 0 session(s) since startup 0 session(s) - peak 0, last 5min 0 0 session(s) per Sec out of max 30, peak 0, last 5min 0 1000 session(s) max min idle cpu 0.00/92.07 Current Stack Size/Max 240K/8192K freeswitch@cpe003> recv 434 bytes from udp/[192.168.22.121]:5060 at 01:49:37.978723: ------------------------------------------------------------------------ REGISTER sip:192.168.22.23 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.121;rport;branch=z9hG4bKzucalaxa Max-Forwards: 70 To: "xq1000" From: "xq1000" ;tag=zckjl Call-ID: jpbkvkxhsniejmo@mx1 CSeq: 233 REGISTER Contact: ;expires=3600 Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE User-Agent: Twinkle/1.10.1 Content-Length: 0 ------------------------------------------------------------------------ send 616 bytes to udp/[192.168.22.121]:5060 at 01:49:37.982396: ------------------------------------------------------------------------ SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.22.121;rport=5060;branch=z9hG4bKzucalaxa From: "xq1000" ;tag=zckjl To: "xq1000" ;tag=8vpmcyatrmDKF Call-ID: jpbkvkxhsniejmo@mx1 CSeq: 233 REGISTER User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces WWW-Authenticate: Digest realm="192.168.22.23", nonce="982ee8e5-79c8-46bd-9500-67078ef26245", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ recv 663 bytes from udp/[192.168.22.121]:5060 at 01:49:46.408530: ------------------------------------------------------------------------ REGISTER sip:192.168.22.23 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.121;rport;branch=z9hG4bKwlserdqf Max-Forwards: 70 To: "xq1000" From: "xq1000" ;tag=zckjl Call-ID: jpbkvkxhsniejmo@mx1 CSeq: 234 REGISTER Contact: ;expires=3600 Authorization: Digest username="1000",realm="192.168.22.23",nonce="982ee8e5-79c8-46bd-9500-67078ef26245",uri="sip:192.168.22.23",response="e0accc7d3ac03bac11420bb97dd0ddbe",algorithm=MD5,cnonce="831d47d7f1",qop=auth,nc=00000001 Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE User-Agent: Twinkle/1.10.1 Content-Length: 0 ------------------------------------------------------------------------ 2018-01-07 01:49:46.411017 [CONSOLE] mod_voicemail.c:4092 Event Thread Started send 571 bytes to udp/[192.168.22.121]:5060 at 01:49:46.421129: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.22.121;rport=5060;branch=z9hG4bKwlserdqf From: "xq1000" ;tag=zckjl To: "xq1000" ;tag=95FDeSUXNX35a Call-ID: jpbkvkxhsniejmo@mx1 CSeq: 234 REGISTER Contact: ;expires=3600 Date: Sun, 07 Jan 2018 07:49:46 GMT User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ send 952 bytes to udp/[192.168.22.121]:5060 at 01:49:46.424089: ------------------------------------------------------------------------ NOTIFY sip:1000@192.168.22.121 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.23;rport;branch=z9hG4bK8QNyUp46F4gjH Max-Forwards: 70 From: ;tag=aF95Fmc1j6Srp To: Call-ID: 2bfde562-6e22-1236-de86-9c5c8e7b1324 CSeq: 117319629 NOTIFY Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Event: message-summary 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: terminated;reason=noresource Content-Type: application/simple-message-summary Content-Length: 92 Messages-Waiting: yes Message-Account: sip:1000@192.168.22.23 Voice-Message: 2/0 (0/0) ------------------------------------------------------------------------ recv 316 bytes from udp/[192.168.22.121]:5060 at 01:49:46.431646: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.22.23;received=192.168.22.23;rport=5060;branch=z9hG4bK8QNyUp46F4gjH To: ;tag=ctrng From: ;tag=aF95Fmc1j6Srp Call-ID: 2bfde562-6e22-1236-de86-9c5c8e7b1324 CSeq: 117319629 NOTIFY Server: Twinkle/1.10.1 Content-Length: 0 ------------------------------------------------------------------------ recv 798 bytes from udp/[192.168.22.121]:5060 at 01:49:54.061144: ------------------------------------------------------------------------ INVITE sip:1100@192.168.22.23 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.121;rport;branch=z9hG4bKbqrfllts Max-Forwards: 70 To: From: "xq1000" ;tag=ewsya Call-ID: ksvnqvxrdulmzyh@mx1 CSeq: 389 INVITE Contact: Content-Type: application/sdp Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE Supported: replaces,norefersub,100rel User-Agent: Twinkle/1.10.1 Content-Length: 313 v=0 o=twinkle 1632699621 1424409132 IN IP4 192.168.22.121 s=- c=IN IP4 192.168.22.121 t=0 0 m=audio 8000 RTP/AVP 98 97 8 0 3 101 a=rtpmap:98 speex/16000 a=rtpmap:97 speex/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 ------------------------------------------------------------------------ send 316 bytes to udp/[192.168.22.121]:5060 at 01:49:54.061820: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.22.121;rport=5060;branch=z9hG4bKbqrfllts From: "xq1000" ;tag=ewsya To: Call-ID: ksvnqvxrdulmzyh@mx1 CSeq: 389 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit Content-Length: 0 ------------------------------------------------------------------------ 2018-01-07 01:49:54.051043 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@192.168.22.23 [ce6e9124-2d9d-4073-923f-9dfc3b87e384] 2018-01-07 01:49:54.051043 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.22.23) Running State Change CS_NEW (Cur 1 Tot 1) 2018-01-07 01:49:54.051043 [DEBUG] sofia.c:9873 sofia/internal/1000@192.168.22.23 receiving invite from 192.168.22.121:5060 version: 1.6.19 git b1b21d0 2017-11-20 16:34:16Z 64bit 2018-01-07 01:49:54.051043 [DEBUG] sofia.c:10044 IP 192.168.22.121 Rejected by acl "domains". Falling back to Digest auth. send 820 bytes to udp/[192.168.22.121]:5060 at 01:49:54.068030: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.22.121;rport=5060;branch=z9hG4bKbqrfllts From: "xq1000" ;tag=ewsya To: ;tag=Br2yHFX4FFgBj Call-ID: ksvnqvxrdulmzyh@mx1 CSeq: 389 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit 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="192.168.22.23", nonce="1f4df9f2-50d0-430f-818f-4a7b741c74c4", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2018-01-07 01:49:54.051043 [DEBUG] sofia.c:2334 detaching session ce6e9124-2d9d-4073-923f-9dfc3b87e384 2018-01-07 01:49:54.051043 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1000@192.168.22.23) State NEW recv 309 bytes from udp/[192.168.22.121]:5060 at 01:49:54.070040: ------------------------------------------------------------------------ ACK sip:1100@192.168.22.23 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.121;rport;branch=z9hG4bKbqrfllts Max-Forwards: 70 To: ;tag=Br2yHFX4FFgBj From: "xq1000" ;tag=ewsya Call-ID: ksvnqvxrdulmzyh@mx1 CSeq: 389 ACK User-Agent: Twinkle/1.10.1 Content-Length: 0 ------------------------------------------------------------------------ recv 1038 bytes from udp/[192.168.22.121]:5060 at 01:49:54.070861: ------------------------------------------------------------------------ INVITE sip:1100@192.168.22.23 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.121;rport;branch=z9hG4bKykqkmqrs Max-Forwards: 70 Proxy-Authorization: Digest username="1000",realm="192.168.22.23",nonce="1f4df9f2-50d0-430f-818f-4a7b741c74c4",uri="sip:1100@192.168.22.23",response="48a6f06ce2eca2d62889f12cf7795ed9",algorithm=MD5,cnonce="92449feb2b",qop=auth,nc=00000001 To: From: "xq1000" ;tag=ewsya Call-ID: ksvnqvxrdulmzyh@mx1 CSeq: 390 INVITE Contact: Content-Type: application/sdp Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE Supported: replaces,norefersub,100rel User-Agent: Twinkle/1.10.1 Content-Length: 313 v=0 o=twinkle 1632699621 1424409132 IN IP4 192.168.22.121 s=- c=IN IP4 192.168.22.121 t=0 0 m=audio 8000 RTP/AVP 98 97 8 0 3 101 a=rtpmap:98 speex/16000 a=rtpmap:97 speex/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 ------------------------------------------------------------------------ send 316 bytes to udp/[192.168.22.121]:5060 at 01:49:54.071596: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.22.121;rport=5060;branch=z9hG4bKykqkmqrs From: "xq1000" ;tag=ewsya To: Call-ID: ksvnqvxrdulmzyh@mx1 CSeq: 390 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit Content-Length: 0 ------------------------------------------------------------------------ 2018-01-07 01:49:54.071105 [DEBUG] sofia.c:2442 Re-attaching to session ce6e9124-2d9d-4073-923f-9dfc3b87e384 2018-01-07 01:49:54.071105 [DEBUG] sofia.c:9873 sofia/internal/1000@192.168.22.23 receiving invite from 192.168.22.121:5060 version: 1.6.19 git b1b21d0 2017-11-20 16:34:16Z 64bit 2018-01-07 01:49:54.071105 [DEBUG] sofia.c:10044 IP 192.168.22.121 Rejected by acl "domains". Falling back to Digest auth. 2018-01-07 01:49:54.091138 [DEBUG] sofia.c:7084 Channel sofia/internal/1000@192.168.22.23 entering state [received][100] 2018-01-07 01:49:54.091138 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=twinkle 1632699621 1424409132 IN IP4 192.168.22.121 s=- c=IN IP4 192.168.22.121 t=0 0 m=audio 8000 RTP/AVP 98 97 8 0 3 101 a=rtpmap:98 speex/16000 a=rtpmap:97 speex/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 2018-01-07 01:49:54.091138 [DEBUG] sofia.c:7486 (sofia/internal/1000@192.168.22.23) State Change CS_NEW -> CS_INIT 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.22.23) Running State Change CS_INIT (Cur 1 Tot 1) 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.22.23) State INIT 2018-01-07 01:49:54.091138 [DEBUG] mod_sofia.c:90 sofia/internal/1000@192.168.22.23 SOFIA INIT 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.22.23 Standard INIT 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.22.23) State Change CS_INIT -> CS_ROUTING 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.22.23) State INIT going to sleep 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.22.23) Running State Change CS_ROUTING (Cur 1 Tot 1) 2018-01-07 01:49:54.091138 [DEBUG] switch_channel.c:2249 (sofia/internal/1000@192.168.22.23) Callstate Change DOWN -> RINGING 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.22.23) State ROUTING 2018-01-07 01:49:54.091138 [DEBUG] mod_sofia.c:143 sofia/internal/1000@192.168.22.23 SOFIA ROUTING 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1000@192.168.22.23 Standard ROUTING 2018-01-07 01:49:54.091138 [INFO] mod_dialplan_xml.c:637 Processing xq1000 <1000>->1100 in context default Dialplan: sofia/internal/1000@192.168.22.23 parsing [default->Local_FXS_Extension] continue=false Dialplan: sofia/internal/1000@192.168.22.23 Regex (PASS) [Local_FXS_Extension] destination_number(1100) =~ /^(1100)$/ break=on-false Dialplan: sofia/internal/1000@192.168.22.23 Action set(dialed_extension=1100) Dialplan: sofia/internal/1000@192.168.22.23 Action export(dialed_extension=1100) Dialplan: sofia/internal/1000@192.168.22.23 Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/1000@192.168.22.23 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) Dialplan: sofia/internal/1000@192.168.22.23 Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/1000@192.168.22.23 Action set(ringback=${us-ring}) Dialplan: sofia/internal/1000@192.168.22.23 Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/1000@192.168.22.23 Action set(call_timeout=10) Dialplan: sofia/internal/1000@192.168.22.23 Action set(hangup_after_bridge=true) Dialplan: sofia/internal/1000@192.168.22.23 Action set(continue_on_fail=true) Dialplan: sofia/internal/1000@192.168.22.23 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/1000@192.168.22.23 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/1000@192.168.22.23 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/1000@192.168.22.23 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1000@192.168.22.23 Action bridge(freetdm/1/1) Dialplan: sofia/internal/1000@192.168.22.23 Action answer() Dialplan: sofia/internal/1000@192.168.22.23 Action sleep(1000) Dialplan: sofia/internal/1000@192.168.22.23 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1000@192.168.22.23) State Change CS_ROUTING -> CS_EXECUTE 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.22.23) State ROUTING going to sleep 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.22.23) Running State Change CS_EXECUTE (Cur 1 Tot 1) 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@192.168.22.23) State EXECUTE 2018-01-07 01:49:54.091138 [DEBUG] mod_sofia.c:198 sofia/internal/1000@192.168.22.23 SOFIA EXECUTE 2018-01-07 01:49:54.091138 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1000@192.168.22.23 Standard EXECUTE EXECUTE sofia/internal/1000@192.168.22.23 set(dialed_extension=1100) 2018-01-07 01:49:54.091138 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1000@192.168.22.23 [dialed_extension]=[1100] EXECUTE sofia/internal/1000@192.168.22.23 export(dialed_extension=1100) 2018-01-07 01:49:54.091138 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1100] EXECUTE sofia/internal/1000@192.168.22.23 bind_meta_app(1 b s execute_extension::dx XML features) 2018-01-07 01:49:54.091138 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *1 execute_extension::dx XML features EXECUTE sofia/internal/1000@192.168.22.23 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1000.2018-01-07-01-49-54.wav) 2018-01-07 01:49:54.091138 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1000.2018-01-07-01-49-54.wav EXECUTE sofia/internal/1000@192.168.22.23 bind_meta_app(3 b s execute_extension::cf XML features) 2018-01-07 01:49:54.091138 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *3 execute_extension::cf XML features EXECUTE sofia/internal/1000@192.168.22.23 set(ringback=%(2000,4000,440,480)) 2018-01-07 01:49:54.091138 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1000@192.168.22.23 [ringback]=[%(2000,4000,440,480)] EXECUTE sofia/internal/1000@192.168.22.23 set(transfer_ringback=local_stream://moh) 2018-01-07 01:49:54.091138 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1000@192.168.22.23 [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/1000@192.168.22.23 set(call_timeout=10) 2018-01-07 01:49:54.091138 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1000@192.168.22.23 [call_timeout]=[10] EXECUTE sofia/internal/1000@192.168.22.23 set(hangup_after_bridge=true) 2018-01-07 01:49:54.091138 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1000@192.168.22.23 [hangup_after_bridge]=[true] EXECUTE sofia/internal/1000@192.168.22.23 set(continue_on_fail=true) 2018-01-07 01:49:54.091138 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1000@192.168.22.23 [continue_on_fail]=[true] EXECUTE sofia/internal/1000@192.168.22.23 hash(insert/192.168.22.23-call_return/1100/1000) EXECUTE sofia/internal/1000@192.168.22.23 hash(insert/192.168.22.23-last_dial_ext/1100/ce6e9124-2d9d-4073-923f-9dfc3b87e384) EXECUTE sofia/internal/1000@192.168.22.23 set(called_party_callgroup=) 2018-01-07 01:49:54.131048 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1000@192.168.22.23 [called_party_callgroup]=[UNDEF] EXECUTE sofia/internal/1000@192.168.22.23 hash(insert/192.168.22.23-last_dial//ce6e9124-2d9d-4073-923f-9dfc3b87e384) EXECUTE sofia/internal/1000@192.168.22.23 bridge(freetdm/1/1) 2018-01-07 01:49:54.131048 [DEBUG] switch_channel.c:1250 sofia/internal/1000@192.168.22.23 EXPORTING[export_vars] [dialed_extension]=[1100] to event 2018-01-07 01:49:54.131048 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-01-07 01:49:54.131048 [DEBUG] mod_freetdm.c:401 Set codec PCMU 20ms 2018-01-07 01:49:54.131048 [DEBUG] mod_freetdm.c:1249 Connect outbound channel FreeTDM/1:1/ 2018-01-07 01:49:54.131048 [NOTICE] switch_channel.c:1104 New Channel FreeTDM/1:1/ [2a61299d-0afa-4208-a93d-7613992c3e18] 2018-01-07 01:49:54.131048 [DEBUG] mod_freetdm.c:1258 (FreeTDM/1:1/) State Change CS_NEW -> CS_INIT 2018-01-07 01:49:54.131048 [DEBUG] mod_freetdm.c:1277 Attached session 2a61299d-0afa-4208-a93d-7613992c3e18 to channel 1:1 2018-01-07 01:49:54.131048 [DEBUG] ftmod_analog.c:83 [s1c1][1:1] Changed state from DOWN to GENRING 2018-01-07 01:49:54.131048 [DEBUG] ftmod_analog.c:437 [s1c1][1:1] ANALOG CHANNEL thread starting. 2018-01-07 01:49:54.131048 [DEBUG] ftdm_io.c:3406 [s1c1][1:1] Enabled software DTMF detector 2018-01-07 01:49:54.131048 [DEBUG] ftmod_analog.c:457 [s1c1][1:1] Initialized DTMF detection 2018-01-07 01:49:54.131048 [DEBUG] ftmod_analog.c:638 [s1c1][1:1] Completed state change from DOWN to GENRING in 2 ms 2018-01-07 01:49:54.131048 [DEBUG] ftmod_analog.c:644 [s1c1][1:1] Executing state handler on 1:1 for GENRING 2018-01-07 01:49:54.131048 [DEBUG] mod_freetdm.c:2370 got FXS sig [PROGRESS] 2018-01-07 01:49:54.131048 [NOTICE] mod_freetdm.c:2387 Ring-Ready FreeTDM/1:1/! 2018-01-07 01:49:54.131048 [DEBUG] switch_channel.c:3346 (FreeTDM/1:1/) Callstate Change DOWN -> RINGING 2018-01-07 01:49:54.151046 [DEBUG] ftmod_wanpipe.c:1005 [s1c1][1:1] First packet read stats: Rx queue len: 0, Rx queue size: 10 2018-01-07 01:49:54.631045 [DEBUG] switch_core_state_machine.c:584 (FreeTDM/1:1/) Running State Change CS_INIT (Cur 2 Tot 2) 2018-01-07 01:49:54.631045 [DEBUG] switch_core_state_machine.c:627 (FreeTDM/1:1/) State INIT 2018-01-07 01:49:54.631045 [DEBUG] mod_freetdm.c:428 (FreeTDM/1:1/) State Change CS_INIT -> CS_ROUTING 2018-01-07 01:49:54.631045 [DEBUG] switch_core_state_machine.c:627 (FreeTDM/1:1/) State INIT going to sleep 2018-01-07 01:49:54.631045 [DEBUG] switch_core_state_machine.c:584 (FreeTDM/1:1/) Running State Change CS_ROUTING (Cur 2 Tot 2) 2018-01-07 01:49:54.631045 [DEBUG] switch_core_state_machine.c:643 (FreeTDM/1:1/) State ROUTING 2018-01-07 01:49:54.631045 [DEBUG] mod_freetdm.c:451 FreeTDM/1:1/ CHANNEL ROUTING 2018-01-07 01:49:54.631045 [DEBUG] switch_ivr_originate.c:67 (FreeTDM/1:1/) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-01-07 01:49:54.631045 [DEBUG] switch_core_state_machine.c:643 (FreeTDM/1:1/) State ROUTING going to sleep 2018-01-07 01:49:54.631045 [DEBUG] switch_core_state_machine.c:584 (FreeTDM/1:1/) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 2) 2018-01-07 01:49:54.631045 [DEBUG] switch_core_state_machine.c:662 (FreeTDM/1:1/) State CONSUME_MEDIA 2018-01-07 01:49:54.631045 [DEBUG] switch_core_state_machine.c:662 (FreeTDM/1:1/) State CONSUME_MEDIA going to sleep 2018-01-07 01:49:54.631045 [INFO] switch_ivr_originate.c:1215 Sending early media 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:98:16000:20:0:1]/[opus:116:48000:20:0:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:98:16000:20:0:1]/[G722:9:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:98:16000:20:0:1]/[PCMU:0:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:98:16000:20:0:1]/[PCMA:8:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:97:8000:20:0:1]/[opus:116:48000:20:0:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:97:8000:20:0:1]/[G722:9:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1] 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/1000@192.168.22.23 PCMA/8000 20 ms 160 samples 64000 bits 1 channels 2018-01-07 01:49:54.651054 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@192.168.22.23 Original read codec set to PCMA:8 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:4767 sofia/internal/1000@192.168.22.23 Set 2833 dtmf send payload to 101 recv payload to 101 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/1000@192.168.22.23] 192.168.22.23 port 27144 -> 192.168.22.121 port 8000 codec: 8 ms: 20 2018-01-07 01:49:54.651054 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:7180 sofia/internal/1000@192.168.22.23 Set 2833 dtmf send payload to 101 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:7187 sofia/internal/1000@192.168.22.23 Set 2833 dtmf receive payload to 101 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:7210 sofia/internal/1000@192.168.22.23 Set rtp dtmf delay to 40 2018-01-07 01:49:54.651054 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1000@192.168.22.23! 2018-01-07 01:49:54.651054 [DEBUG] switch_channel.c:3474 (sofia/internal/1000@192.168.22.23) Callstate Change RINGING -> EARLY 2018-01-07 01:49:54.651054 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/internal/1000@192.168.22.23. 2018-01-07 01:49:54.651054 [DEBUG] mod_sofia.c:2364 Ring SDP: v=0 o=FreeSWITCH 1515284250 1515284251 IN IP4 192.168.22.23 s=FreeSWITCH c=IN IP4 192.168.22.23 t=0 0 m=audio 27144 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2018-01-07 01:49:54.651054 [DEBUG] switch_ivr_originate.c:1273 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2018-01-07 01:49:54.651054 [DEBUG] switch_core_codec.c:223 sofia/internal/1000@192.168.22.23 Push codec L16:100 send 1109 bytes to udp/[192.168.22.121]:5060 at 01:49:54.669763: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.22.121;rport=5060;branch=z9hG4bKykqkmqrs From: "xq1000" ;tag=ewsya To: ;tag=c1UQKae8cr6XD Call-ID: ksvnqvxrdulmzyh@mx1 CSeq: 390 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit 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 Content-Type: application/sdp Content-Disposition: session Content-Length: 222 Remote-Party-ID: "1100" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515284250 1515284251 IN IP4 192.168.22.23 s=FreeSWITCH c=IN IP4 192.168.22.23 t=0 0 m=audio 27144 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2018-01-07 01:49:54.651054 [DEBUG] switch_ivr_originate.c:1342 Play Ringback Tone [%(2000,4000,440,480)] 2018-01-07 01:49:54.691083 [DEBUG] sofia.c:7084 Channel sofia/internal/1000@192.168.22.23 entering state [early][183] 2018-01-07 01:49:54.731049 [DEBUG] ftmod_wanpipe.c:1678 [s1c1][1:1] read wanpipe event 5 2018-01-07 01:49:54.731049 [DEBUG] ftmod_wanpipe.c:1462 [s1c1][1:1] Got wanpipe OFFHOOK 2018-01-07 01:49:54.731049 [DEBUG] ftmod_wanpipe.c:1685 [s1c1][1:1] Ignoring event for now 2018-01-07 01:49:54.811034 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed. 2018-01-07 01:49:54.891028 [DEBUG] ftmod_wanpipe.c:1642 [s1c1][1:1] Diff since last event = 153 ms, delivering OFFHOOK now 2018-01-07 01:49:54.891028 [DEBUG] ftmod_analog.c:1002 [s1c1][1:1] Received event [OFFHOOK] in state [GENRING] 2018-01-07 01:49:54.891028 [DEBUG] ftmod_analog.c:1090 [s1c1][1:1] Changed state from GENRING to UP 2018-01-07 01:49:54.891028 [DEBUG] ftmod_analog.c:638 [s1c1][1:1] Completed state change from GENRING to UP in 4 ms 2018-01-07 01:49:54.891028 [DEBUG] ftmod_analog.c:644 [s1c1][1:1] Executing state handler on 1:1 for UP 2018-01-07 01:49:54.891028 [DEBUG] ftmod_analog.c:657 [s1c1][1:1] Cancel FSK transmit due to early answer. 2018-01-07 01:49:54.891028 [DEBUG] mod_freetdm.c:2370 got FXS sig [UP] 2018-01-07 01:49:54.891028 [NOTICE] mod_freetdm.c:2377 Channel [FreeTDM/1:1/] has been answered 2018-01-07 01:49:54.891028 [DEBUG] switch_channel.c:3773 (FreeTDM/1:1/) Callstate Change RINGING -> ACTIVE 2018-01-07 01:49:54.891028 [DEBUG] ftdm_io.c:3406 [s1c1][1:1] Enabled software DTMF detector 2018-01-07 01:49:54.911028 [DEBUG] switch_core_codec.c:248 sofia/internal/1000@192.168.22.23 Restore previous codec PCMA:8. 2018-01-07 01:49:54.911028 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/internal/1000@192.168.22.23. 2018-01-07 01:49:54.911028 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/1000@192.168.22.23: v=0 o=FreeSWITCH 1515284250 1515284252 IN IP4 192.168.22.23 s=FreeSWITCH c=IN IP4 192.168.22.23 t=0 0 m=audio 27144 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv send 1076 bytes to udp/[192.168.22.121]:5060 at 01:49:54.918870: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.22.121;rport=5060;branch=z9hG4bKykqkmqrs From: "xq1000" ;tag=ewsya To: ;tag=c1UQKae8cr6XD Call-ID: ksvnqvxrdulmzyh@mx1 CSeq: 390 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit 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 Content-Type: application/sdp Content-Disposition: session Content-Length: 222 Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515284250 1515284251 IN IP4 192.168.22.23 s=FreeSWITCH c=IN IP4 192.168.22.23 t=0 0 m=audio 27144 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2018-01-07 01:49:54.911028 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/internal/1000@192.168.22.23] has been answered 2018-01-07 01:49:54.911028 [DEBUG] switch_channel.c:3773 (sofia/internal/1000@192.168.22.23) Callstate Change EARLY -> ACTIVE 2018-01-07 01:49:54.911028 [DEBUG] sofia.c:7084 Channel sofia/internal/1000@192.168.22.23 entering state [completed][200] 2018-01-07 01:49:54.911028 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [FreeTDM/1:1/] 2018-01-07 01:49:54.911028 [DEBUG] switch_ivr_bridge.c:1614 (FreeTDM/1:1/) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2018-01-07 01:49:54.911028 [DEBUG] switch_core_state_machine.c:584 (FreeTDM/1:1/) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 2) 2018-01-07 01:49:54.911028 [DEBUG] switch_core_state_machine.c:653 (FreeTDM/1:1/) State EXCHANGE_MEDIA 2018-01-07 01:49:54.911028 [DEBUG] mod_freetdm.c:673 CHANNEL EXCHANGE_MEDIA recv 568 bytes from udp/[192.168.22.121]:5060 at 01:49:54.925733: ------------------------------------------------------------------------ ACK sip:1100@192.168.22.23:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.22.121;rport;branch=z9hG4bKrmxueras Max-Forwards: 70 Proxy-Authorization: Digest username="1000",realm="192.168.22.23",nonce="1f4df9f2-50d0-430f-818f-4a7b741c74c4",uri="sip:1100@192.168.22.23",response="48a6f06ce2eca2d62889f12cf7795ed9",algorithm=MD5,cnonce="92449feb2b",qop=auth,nc=00000001 To: ;tag=c1UQKae8cr6XD From: "xq1000" ;tag=ewsya Call-ID: ksvnqvxrdulmzyh@mx1 CSeq: 390 ACK User-Agent: Twinkle/1.10.1 Content-Length: 0 ------------------------------------------------------------------------ 2018-01-07 01:49:54.931034 [DEBUG] sofia.c:7084 Channel sofia/internal/1000@192.168.22.23 entering state [ready][200] 2018-01-07 01:49:54.971023 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed. 2018-01-07 01:49:54.971023 [DEBUG] ftmod_wanpipe.c:941 [s1c1][1:1] First packet write stats: Tx queue len: 0, Tx queue size: 0, Tx idle: 0 recv 435 bytes from udp/[192.168.22.122]:5060 at 01:51:10.483096: ------------------------------------------------------------------------ REGISTER sip:192.168.22.23 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.122;rport;branch=z9hG4bKrnnyzlxo Max-Forwards: 70 To: "xq1001" From: "xq1001" ;tag=mdmjv Call-ID: zzywitobkwwnxdp@mx16 CSeq: 949 REGISTER Contact: ;expires=3600 Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE User-Agent: Twinkle/1.10.1 Content-Length: 0 ------------------------------------------------------------------------ send 617 bytes to udp/[192.168.22.122]:5060 at 01:51:10.486602: ------------------------------------------------------------------------ SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.22.122;rport=5060;branch=z9hG4bKrnnyzlxo From: "xq1001" ;tag=mdmjv To: "xq1001" ;tag=DaNgN5yBa1vgS Call-ID: zzywitobkwwnxdp@mx16 CSeq: 949 REGISTER User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces WWW-Authenticate: Digest realm="192.168.22.23", nonce="84b44a4b-60c3-454a-ab09-ecc3aa85e0e7", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ recv 664 bytes from udp/[192.168.22.122]:5060 at 01:51:28.844920: ------------------------------------------------------------------------ REGISTER sip:192.168.22.23 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.122;rport;branch=z9hG4bKzxwxmvdb Max-Forwards: 70 To: "xq1001" From: "xq1001" ;tag=mdmjv Call-ID: zzywitobkwwnxdp@mx16 CSeq: 950 REGISTER Contact: ;expires=3600 Authorization: Digest username="1001",realm="192.168.22.23",nonce="84b44a4b-60c3-454a-ab09-ecc3aa85e0e7",uri="sip:192.168.22.23",response="1a63f6e4faa3492dea40e12baa5d54f1",algorithm=MD5,cnonce="58b293c21c",qop=auth,nc=00000001 Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE User-Agent: Twinkle/1.10.1 Content-Length: 0 ------------------------------------------------------------------------ send 572 bytes to udp/[192.168.22.122]:5060 at 01:51:28.858644: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.22.122;rport=5060;branch=z9hG4bKzxwxmvdb From: "xq1001" ;tag=mdmjv To: "xq1001" ;tag=eKe9p0FF79j3m Call-ID: zzywitobkwwnxdp@mx16 CSeq: 950 REGISTER Contact: ;expires=3600 Date: Sun, 07 Jan 2018 07:51:28 GMT User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ recv 571 bytes from udp/[192.168.22.122]:5060 at 01:51:28.860952: ------------------------------------------------------------------------ PUBLISH sip:1001@192.168.22.23 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.122;rport;branch=z9hG4bKhgrfhefv Max-Forwards: 70 To: "xq1001" From: "xq1001" ;tag=hgpte Call-ID: tvqhmktmxunwsli@mx16 CSeq: 411 PUBLISH Content-Type: application/pidf+xml Event: presence Expires: 3600 User-Agent: Twinkle/1.10.1 Content-Length: 192 open ------------------------------------------------------------------------ send 721 bytes to udp/[192.168.22.122]:5060 at 01:51:28.867655: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.22.122;rport=5060;branch=z9hG4bKhgrfhefv From: "xq1001" ;tag=hgpte To: "xq1001" ;tag=Fv71rU0j4j9Ng Call-ID: tvqhmktmxunwsli@mx16 CSeq: 411 PUBLISH Contact: Expires: 3600 User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit 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 SIP-ETag: E4BJ6259 Content-Length: 0 ------------------------------------------------------------------------ send 952 bytes to udp/[192.168.22.122]:5060 at 01:51:28.909429: ------------------------------------------------------------------------ NOTIFY sip:1001@192.168.22.122 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.23;rport;branch=z9hG4bK90eQXHNaDD74c Max-Forwards: 70 From: ;tag=g50ttpHp1UZ8B To: Call-ID: 6913f6dc-6e22-1236-de86-9c5c8e7b1324 CSeq: 117319680 NOTIFY Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Event: message-summary 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: terminated;reason=noresource Content-Type: application/simple-message-summary Content-Length: 92 Messages-Waiting: yes Message-Account: sip:1001@192.168.22.23 Voice-Message: 1/0 (0/0) ------------------------------------------------------------------------ recv 316 bytes from udp/[192.168.22.122]:5060 at 01:51:28.914401: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.22.23;received=192.168.22.23;rport=5060;branch=z9hG4bK90eQXHNaDD74c To: ;tag=ojxwy From: ;tag=g50ttpHp1UZ8B Call-ID: 6913f6dc-6e22-1236-de86-9c5c8e7b1324 CSeq: 117319680 NOTIFY Server: Twinkle/1.10.1 Content-Length: 0 ------------------------------------------------------------------------ recv 798 bytes from udp/[192.168.22.122]:5060 at 01:51:43.142660: ------------------------------------------------------------------------ INVITE sip:9664@192.168.22.23 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.122;rport;branch=z9hG4bKsjxiuufv Max-Forwards: 70 To: From: "xq1001" ;tag=sdofb Call-ID: hxtpeywcrtubfgu@mx16 CSeq: 720 INVITE Contact: Content-Type: application/sdp Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE Supported: replaces,norefersub,100rel User-Agent: Twinkle/1.10.1 Content-Length: 312 v=0 o=twinkle 1321715876 379379822 IN IP4 192.168.22.122 s=- c=IN IP4 192.168.22.122 t=0 0 m=audio 8000 RTP/AVP 98 97 8 0 3 101 a=rtpmap:98 speex/16000 a=rtpmap:97 speex/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 ------------------------------------------------------------------------ send 317 bytes to udp/[192.168.22.122]:5060 at 01:51:43.143897: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.22.122;rport=5060;branch=z9hG4bKsjxiuufv From: "xq1001" ;tag=sdofb To: Call-ID: hxtpeywcrtubfgu@mx16 CSeq: 720 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit Content-Length: 0 ------------------------------------------------------------------------ 2018-01-07 01:51:43.111399 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@192.168.22.23 [412c1118-efb2-4f76-b912-fa6455b7dbf9] 2018-01-07 01:51:43.111399 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.22.23) Running State Change CS_NEW (Cur 3 Tot 3) 2018-01-07 01:51:43.111399 [DEBUG] sofia.c:9873 sofia/internal/1001@192.168.22.23 receiving invite from 192.168.22.122:5060 version: 1.6.19 git b1b21d0 2017-11-20 16:34:16Z 64bit 2018-01-07 01:51:43.111399 [DEBUG] sofia.c:10044 IP 192.168.22.122 Rejected by acl "domains". Falling back to Digest auth. send 821 bytes to udp/[192.168.22.122]:5060 at 01:51:43.149078: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.22.122;rport=5060;branch=z9hG4bKsjxiuufv From: "xq1001" ;tag=sdofb To: ;tag=HetKvH2Sy4NUQ Call-ID: hxtpeywcrtubfgu@mx16 CSeq: 720 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit 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="192.168.22.23", nonce="e292d3a8-95c8-4233-8f32-042467938893", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2018-01-07 01:51:43.111399 [DEBUG] sofia.c:2334 detaching session 412c1118-efb2-4f76-b912-fa6455b7dbf9 2018-01-07 01:51:43.111399 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1001@192.168.22.23) State NEW recv 310 bytes from udp/[192.168.22.122]:5060 at 01:51:43.150767: ------------------------------------------------------------------------ ACK sip:9664@192.168.22.23 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.122;rport;branch=z9hG4bKsjxiuufv Max-Forwards: 70 To: ;tag=HetKvH2Sy4NUQ From: "xq1001" ;tag=sdofb Call-ID: hxtpeywcrtubfgu@mx16 CSeq: 720 ACK User-Agent: Twinkle/1.10.1 Content-Length: 0 ------------------------------------------------------------------------ recv 1038 bytes from udp/[192.168.22.122]:5060 at 01:51:43.151381: ------------------------------------------------------------------------ INVITE sip:9664@192.168.22.23 SIP/2.0 Via: SIP/2.0/UDP 192.168.22.122;rport;branch=z9hG4bKugrvoxsi Max-Forwards: 70 Proxy-Authorization: Digest username="1001",realm="192.168.22.23",nonce="e292d3a8-95c8-4233-8f32-042467938893",uri="sip:9664@192.168.22.23",response="506705bfb6087c87c23296671ef7ab84",algorithm=MD5,cnonce="d1c237211e",qop=auth,nc=00000001 To: From: "xq1001" ;tag=sdofb Call-ID: hxtpeywcrtubfgu@mx16 CSeq: 721 INVITE Contact: Content-Type: application/sdp Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE Supported: replaces,norefersub,100rel User-Agent: Twinkle/1.10.1 Content-Length: 312 v=0 o=twinkle 1321715876 379379822 IN IP4 192.168.22.122 s=- c=IN IP4 192.168.22.122 t=0 0 m=audio 8000 RTP/AVP 98 97 8 0 3 101 a=rtpmap:98 speex/16000 a=rtpmap:97 speex/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 ------------------------------------------------------------------------ send 317 bytes to udp/[192.168.22.122]:5060 at 01:51:43.152794: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.22.122;rport=5060;branch=z9hG4bKugrvoxsi From: "xq1001" ;tag=sdofb To: Call-ID: hxtpeywcrtubfgu@mx16 CSeq: 721 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit Content-Length: 0 ------------------------------------------------------------------------ 2018-01-07 01:51:43.151051 [DEBUG] sofia.c:2442 Re-attaching to session 412c1118-efb2-4f76-b912-fa6455b7dbf9 2018-01-07 01:51:43.151051 [DEBUG] sofia.c:9873 sofia/internal/1001@192.168.22.23 receiving invite from 192.168.22.122:5060 version: 1.6.19 git b1b21d0 2017-11-20 16:34:16Z 64bit 2018-01-07 01:51:43.151051 [DEBUG] sofia.c:10044 IP 192.168.22.122 Rejected by acl "domains". Falling back to Digest auth. 2018-01-07 01:51:43.171058 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@192.168.22.23 entering state [received][100] 2018-01-07 01:51:43.171058 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=twinkle 1321715876 379379822 IN IP4 192.168.22.122 s=- c=IN IP4 192.168.22.122 t=0 0 m=audio 8000 RTP/AVP 98 97 8 0 3 101 a=rtpmap:98 speex/16000 a=rtpmap:97 speex/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 2018-01-07 01:51:43.171058 [DEBUG] sofia.c:7486 (sofia/internal/1001@192.168.22.23) State Change CS_NEW -> CS_INIT 2018-01-07 01:51:43.171058 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.22.23) Running State Change CS_INIT (Cur 3 Tot 3) 2018-01-07 01:51:43.171058 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.22.23) State INIT 2018-01-07 01:51:43.171058 [DEBUG] mod_sofia.c:90 sofia/internal/1001@192.168.22.23 SOFIA INIT 2018-01-07 01:51:43.171058 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@192.168.22.23 Standard INIT 2018-01-07 01:51:43.171058 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@192.168.22.23) State Change CS_INIT -> CS_ROUTING 2018-01-07 01:51:43.171058 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.22.23) State INIT going to sleep 2018-01-07 01:51:43.171058 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.22.23) Running State Change CS_ROUTING (Cur 3 Tot 3) 2018-01-07 01:51:43.171058 [DEBUG] switch_channel.c:2249 (sofia/internal/1001@192.168.22.23) Callstate Change DOWN -> RINGING 2018-01-07 01:51:43.171058 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.22.23) State ROUTING 2018-01-07 01:51:43.171058 [DEBUG] mod_sofia.c:143 sofia/internal/1001@192.168.22.23 SOFIA ROUTING 2018-01-07 01:51:43.171058 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1001@192.168.22.23 Standard ROUTING 2018-01-07 01:51:43.171058 [INFO] mod_dialplan_xml.c:637 Processing xq1001 <1001>->9664 in context default Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->Local_FXS_Extension] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [Local_FXS_Extension] destination_number(9664) =~ /^(1100)$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->freetdm.example.com] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (PASS) [freetdm.example.com] ${toll_allow}(domestic,international,local) =~ /local/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [freetdm.example.com] destination_number(9664) =~ /^9(\d{10})$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->unloop] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->tod_example] continue=true Dialplan: sofia/internal/1001@192.168.22.23 Date/TimeMatch (FAIL) [tod_example] break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1001@192.168.22.23 Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [global-intercept] destination_number(9664) =~ /^886$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [group-intercept] destination_number(9664) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [intercept-ext] destination_number(9664) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->redial] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [redial] destination_number(9664) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->global] continue=true Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [global] ${default_password}(4951) =~ /^1234$/ break=never Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never Dialplan: sofia/internal/1001@192.168.22.23 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [global] ${switch_r_sdp}(v=0 o=twinkle 1321715876 379379822 IN IP4 192.168.22.122 s=- c=IN IP4 192.168.22.122 t=0 0 m=audio 8000 RTP/AVP 98 97 8 0 3 101 a=rtpmap:98 speex/16000 a=rtpmap:97 speex/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never Dialplan: sofia/internal/1001@192.168.22.23 Absolute Condition [global] Dialplan: sofia/internal/1001@192.168.22.23 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1001@192.168.22.23 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1001@192.168.22.23 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1001@192.168.22.23 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [snom-demo-2] destination_number(9664) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [snom-demo-1] destination_number(9664) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [eavesdrop] destination_number(9664) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [eavesdrop] destination_number(9664) =~ /^779$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->call_return] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [call_return] destination_number(9664) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->del-group] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [del-group] destination_number(9664) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->add-group] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [add-group] destination_number(9664) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [call-group-simo] destination_number(9664) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [call-group-order] destination_number(9664) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [extension-intercom] destination_number(9664) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [Local_Extension] destination_number(9664) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->Local_Extension_Skinny] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [Local_Extension_Skinny] destination_number(9664) =~ /^(11[01][0-9])$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->group_dial_sales] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [group_dial_sales] destination_number(9664) =~ /^2000$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->group_dial_support] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [group_dial_support] destination_number(9664) =~ /^2001$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->group_dial_billing] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [group_dial_billing] destination_number(9664) =~ /^2002$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->operator] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [operator] destination_number(9664) =~ /^(operator|0)$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->vmain] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [vmain] destination_number(9664) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->sip_uri] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [sip_uri] destination_number(9664) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->nb_conferences] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [nb_conferences] destination_number(9664) =~ /^(30\d{2})$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->wb_conferences] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [wb_conferences] destination_number(9664) =~ /^(31\d{2})$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->uwb_conferences] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [uwb_conferences] destination_number(9664) =~ /^(32\d{2})$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [cdquality_conferences] destination_number(9664) =~ /^(33\d{2})$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->cdquality_stereo_conferences] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [cdquality_stereo_conferences] destination_number(9664) =~ /^(35\d{2}).*?-screen$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->conference-canvases] continue=true Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [conference-canvases] destination_number(9664) =~ /(35\d{2})-canvas-(\d+)/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->conf mod] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [conf mod] destination_number(9664) =~ /^6070-moderator$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->cdquality_conferences] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [cdquality_conferences] destination_number(9664) =~ /^(35\d{2})$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(9664) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [mad_boss_intercom] destination_number(9664) =~ /^0911$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [mad_boss_intercom] destination_number(9664) =~ /^0912$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->mad_boss] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [mad_boss] destination_number(9664) =~ /^0913$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->ivr_demo] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [ivr_demo] destination_number(9664) =~ /^5000$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->dynamic_conference] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [dynamic_conference] destination_number(9664) =~ /^5001$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->rtp_multicast_page] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [rtp_multicast_page] destination_number(9664) =~ /^pagegroup$|^7243$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->park] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [park] destination_number(9664) =~ /^5900$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->unpark] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [unpark] destination_number(9664) =~ /^5901$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->valet_park] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [valet_park] destination_number(9664) =~ /^(6000)$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->valet_park] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [valet_park] destination_number(9664) =~ /^((?!6000)60\d{2})$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->park] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [park] destination_number(9664) =~ /park\+(\d+)/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->unpark] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [unpark] destination_number(9664) =~ /^parking$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->park] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [park] destination_number(9664) =~ /callpark/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->unpark] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [unpark] destination_number(9664) =~ /pickup/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->wait] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [wait] destination_number(9664) =~ /^wait$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->fax_receive] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [fax_receive] destination_number(9664) =~ /^9178$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->fax_transmit] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [fax_transmit] destination_number(9664) =~ /^9179$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->ringback_180] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [ringback_180] destination_number(9664) =~ /^9180$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->ringback_183_uk_ring] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [ringback_183_uk_ring] destination_number(9664) =~ /^9181$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->ringback_183_music_ring] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [ringback_183_music_ring] destination_number(9664) =~ /^9182$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(9664) =~ /^9183$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->ringback_post_answer_music] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [ringback_post_answer_music] destination_number(9664) =~ /^9184$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->ClueCon] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [ClueCon] destination_number(9664) =~ /^9191$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->show_info] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [show_info] destination_number(9664) =~ /^9192$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->video_record] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [video_record] destination_number(9664) =~ /^9193$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->video_playback] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [video_playback] destination_number(9664) =~ /^9194$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->delay_echo] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [delay_echo] destination_number(9664) =~ /^9195$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->echo] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [echo] destination_number(9664) =~ /^9196$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->milliwatt] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [milliwatt] destination_number(9664) =~ /^9197$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->tone_stream] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [tone_stream] destination_number(9664) =~ /^9198$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->zrtp_enrollement] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [zrtp_enrollement] destination_number(9664) =~ /^9787$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [default->hold_music] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (PASS) [hold_music] destination_number(9664) =~ /^9664$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [hold_music] ${rtp_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 ANTI-Action set(zrtp_secure_media=true) Dialplan: sofia/internal/1001@192.168.22.23 ANTI-Action answer() Dialplan: sofia/internal/1001@192.168.22.23 ANTI-Action playback(silence_stream://2000) Dialplan: sofia/internal/1001@192.168.22.23 ANTI-Action execute_extension(is_zrtp_secure XML features) Dialplan: sofia/internal/1001@192.168.22.23 ANTI-Action playback(local_stream://moh) 2018-01-07 01:51:43.191051 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1001@192.168.22.23) State Change CS_ROUTING -> CS_EXECUTE 2018-01-07 01:51:43.191051 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.22.23) State ROUTING going to sleep 2018-01-07 01:51:43.191051 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.22.23) Running State Change CS_EXECUTE (Cur 3 Tot 3) 2018-01-07 01:51:43.191051 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@192.168.22.23) State EXECUTE 2018-01-07 01:51:43.191051 [DEBUG] mod_sofia.c:198 sofia/internal/1001@192.168.22.23 SOFIA EXECUTE 2018-01-07 01:51:43.191051 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1001@192.168.22.23 Standard EXECUTE EXECUTE sofia/internal/1001@192.168.22.23 hash(insert/192.168.22.23-spymap/1001/412c1118-efb2-4f76-b912-fa6455b7dbf9) EXECUTE sofia/internal/1001@192.168.22.23 hash(insert/192.168.22.23-last_dial/1001/9664) EXECUTE sofia/internal/1001@192.168.22.23 hash(insert/192.168.22.23-last_dial/global/412c1118-efb2-4f76-b912-fa6455b7dbf9) EXECUTE sofia/internal/1001@192.168.22.23 export(RFC2822_DATE=Sun, 07 Jan 2018 01:51:43 -0600) 2018-01-07 01:51:43.211074 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Sun, 07 Jan 2018 01:51:43 -0600] EXECUTE sofia/internal/1001@192.168.22.23 set(zrtp_secure_media=true) 2018-01-07 01:51:43.211074 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@192.168.22.23 [zrtp_secure_media]=[true] EXECUTE sofia/internal/1001@192.168.22.23 answer() 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:98:16000:20:0:1]/[opus:116:48000:20:0:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:98:16000:20:0:1]/[G722:9:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:98:16000:20:0:1]/[PCMU:0:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:98:16000:20:0:1]/[PCMA:8:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:97:8000:20:0:1]/[opus:116:48000:20:0:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:97:8000:20:0:1]/[G722:9:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [speex:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1] 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/1001@192.168.22.23 PCMA/8000 20 ms 160 samples 64000 bits 1 channels 2018-01-07 01:51:43.211074 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@192.168.22.23 Original read codec set to PCMA:8 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:4767 sofia/internal/1001@192.168.22.23 Set 2833 dtmf send payload to 101 recv payload to 101 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/1001@192.168.22.23] 192.168.22.23 port 31882 -> 192.168.22.122 port 8000 codec: 8 ms: 20 2018-01-07 01:51:43.211074 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:7180 sofia/internal/1001@192.168.22.23 Set 2833 dtmf send payload to 101 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:7187 sofia/internal/1001@192.168.22.23 Set 2833 dtmf receive payload to 101 2018-01-07 01:51:43.211074 [DEBUG] switch_core_media.c:7210 sofia/internal/1001@192.168.22.23 Set rtp dtmf delay to 40 2018-01-07 01:51:43.211074 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1001@192.168.22.23! 2018-01-07 01:51:43.211074 [DEBUG] switch_channel.c:3474 (sofia/internal/1001@192.168.22.23) Callstate Change RINGING -> EARLY 2018-01-07 01:51:43.231045 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/internal/1001@192.168.22.23. 2018-01-07 01:51:43.231045 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/1001@192.168.22.23: v=0 o=FreeSWITCH 1515279621 1515279622 IN IP4 192.168.22.23 s=FreeSWITCH c=IN IP4 192.168.22.23 t=0 0 m=audio 31882 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv send 1096 bytes to udp/[192.168.22.122]:5060 at 01:51:43.233937: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.22.122;rport=5060;branch=z9hG4bKugrvoxsi From: "xq1001" ;tag=sdofb To: ;tag=jQKcycKXUDceK Call-ID: hxtpeywcrtubfgu@mx16 CSeq: 721 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19+git~20171120T163416Z~b1b21d0695~64bit 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 Content-Type: application/sdp Content-Disposition: session Content-Length: 222 Remote-Party-ID: "9664" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515279621 1515279622 IN IP4 192.168.22.23 s=FreeSWITCH c=IN IP4 192.168.22.23 t=0 0 m=audio 31882 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2018-01-07 01:51:43.231045 [NOTICE] mod_dptools.c:1312 Channel [sofia/internal/1001@192.168.22.23] has been answered 2018-01-07 01:51:43.231045 [DEBUG] switch_channel.c:3773 (sofia/internal/1001@192.168.22.23) Callstate Change EARLY -> ACTIVE 2018-01-07 01:51:43.231045 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@192.168.22.23 entering state [completed][200] EXECUTE sofia/internal/1001@192.168.22.23 playback(silence_stream://2000) 2018-01-07 01:51:43.231045 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms recv 569 bytes from udp/[192.168.22.122]:5060 at 01:51:43.252086: ------------------------------------------------------------------------ ACK sip:9664@192.168.22.23:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.22.122;rport;branch=z9hG4bKdiperioq Max-Forwards: 70 Proxy-Authorization: Digest username="1001",realm="192.168.22.23",nonce="e292d3a8-95c8-4233-8f32-042467938893",uri="sip:9664@192.168.22.23",response="506705bfb6087c87c23296671ef7ab84",algorithm=MD5,cnonce="d1c237211e",qop=auth,nc=00000001 To: ;tag=jQKcycKXUDceK From: "xq1001" ;tag=sdofb Call-ID: hxtpeywcrtubfgu@mx16 CSeq: 721 ACK User-Agent: Twinkle/1.10.1 Content-Length: 0 ------------------------------------------------------------------------ 2018-01-07 01:51:43.251043 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@192.168.22.23 entering state [ready][200] 2018-01-07 01:51:43.331026 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed. 2018-01-07 01:51:45.211035 [DEBUG] switch_ivr_play_say.c:1942 done playing file silence_stream://2000 EXECUTE sofia/internal/1001@192.168.22.23 execute_extension(is_zrtp_secure XML features) 2018-01-07 01:51:45.211035 [INFO] mod_dialplan_xml.c:637 Processing xq1001 <1001>->is_zrtp_secure in context features Dialplan: sofia/internal/1001@192.168.22.23 parsing [features->dx] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [dx] destination_number(is_zrtp_secure) =~ /^dx$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [features->att_xfer] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [att_xfer] destination_number(is_zrtp_secure) =~ /^att_xfer$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [features->is_transfer] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [is_transfer] destination_number(is_zrtp_secure) =~ /^is_transfer$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [features->cf] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [cf] destination_number(is_zrtp_secure) =~ /^cf$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [features->please_hold] continue=false Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [please_hold] destination_number(is_zrtp_secure) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 parsing [features->is_zrtp_secure] continue=true Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [is_zrtp_secure] ${zrtp_secure_media_confirmed}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1001@192.168.22.23 ANTI-Action eval(not_secure) Dialplan: sofia/internal/1001@192.168.22.23 parsing [features->is_secure] continue=true Dialplan: sofia/internal/1001@192.168.22.23 Regex (FAIL) [is_secure] ${sip_via_protocol}(udp) =~ /tls/ break=on-false 2018-01-07 01:51:45.211035 [NOTICE] switch_core_session.c:2914 Execute eval(not_secure) EXECUTE sofia/internal/1001@192.168.22.23 eval(not_secure) EXECUTE sofia/internal/1001@192.168.22.23 playback(local_stream://moh) 2018-01-07 01:51:45.231039 [DEBUG] mod_local_stream.c:871 Opening Stream [moh/8000] 8000hz 2018-01-07 01:51:45.231039 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms