b0ab7c72-8199-4a3a-b3dc-e1ec99051cbd 2017-04-06 17:41:19.967277 [DEBUG] switch_core_state_machine.c:181 sofia/external/068277041@62.94.71.28 Standard DESTROY b0ab7c72-8199-4a3a-b3dc-e1ec99051cbd 2017-04-06 17:41:19.967277 [DEBUG] switch_core_state_machine.c:751 (sofia/external/068277041@62.94.71.28) State DESTROY going to sleep ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [NOTICE] switch_channel.c:1104 New Channel sofia/external/339xxxxxxx@83.xx.xx.xx [ccda4f1e-0f71-4b92-8b37-068702db5e65] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@83.xx.xx.xx) Running State Change CS_NEW (Cur 1 Tot 277) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] sofia.c:9825 sofia/external/339xxxxxxx@83.xx.xx.xx receiving invite from 83.211.227.21:5060 version: 1.6.16 -33-e6d643b 64bit ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] sofia.c:7048 Channel sofia/external/339xxxxxxx@83.xx.xx.xx entering state [received][100] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] sofia.c:7058 Remote SDP: ccda4f1e-0f71-4b92-8b37-068702db5e65 v=0 ccda4f1e-0f71-4b92-8b37-068702db5e65 o=CiscoSystemsSIP-GW-UserAgent 3811 5892 IN IP4 83.xx.xx.xx ccda4f1e-0f71-4b92-8b37-068702db5e65 s=SIP Call ccda4f1e-0f71-4b92-8b37-068702db5e65 c=IN IP4 83.211.227.20 ccda4f1e-0f71-4b92-8b37-068702db5e65 t=0 0 ccda4f1e-0f71-4b92-8b37-068702db5e65 m=audio 54776 RTP/AVP 18 8 0 4 3 2 125 101 ccda4f1e-0f71-4b92-8b37-068702db5e65 c=IN IP4 83.211.227.20 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=rtpmap:18 G729/8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=fmtp:18 annexb=yes ccda4f1e-0f71-4b92-8b37-068702db5e65 a=rtpmap:8 PCMA/8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=rtpmap:0 PCMU/8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=rtpmap:4 G723/8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=fmtp:4 bitrate=5.3;annexa=no ccda4f1e-0f71-4b92-8b37-068702db5e65 a=rtpmap:3 GSM/8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=rtpmap:2 G726-32/8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=rtpmap:125 X-CCD/8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=rtpmap:101 telephone-event/8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=fmtp:101 0-16 ccda4f1e-0f71-4b92-8b37-068702db5e65 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:3889 Activate Buggy RFC2833 Mode! ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G723:4:8000:30:6300:1]/[G722:9:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G723:4:8000:30:6300:1]/[opus:116:48000:20:0:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G723:4:8000:30:6300:1]/[PCMU:0:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G723:4:8000:30:6300:1]/[PCMA:8:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G723:4:8000:30:6300:1]/[GSM:3:8000:20:13200:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [GSM:3:8000:20:13200:1]/[GSM:3:8000:20:13200:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [GSM:3:8000:20:13200:1] ++++ is saved as a match ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G726-32:2:8000:20:0:1]/[G722:9:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G726-32:2:8000:20:0:1]/[opus:116:48000:20:0:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMU:0:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMA:8:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G726-32:2:8000:20:0:1]/[GSM:3:8000:20:13200:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [X-CCD:125:8000:20:0:1]/[G722:9:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [X-CCD:125:8000:20:0:1]/[opus:116:48000:20:0:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [X-CCD:125:8000:20:0:1]/[PCMU:0:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [X-CCD:125:8000:20:0:1]/[PCMA:8:8000:20:64000:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [X-CCD:125:8000:20:0:1]/[GSM:3:8000:20:13200:1] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:3049 Set Codec sofia/external/339xxxxxxx@83.xx.xx.xx PCMA/8000 20 ms 160 samples 64000 bits 1 channels ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_codec.c:111 sofia/external/339xxxxxxx@83.xx.xx.xx Original read codec set to PCMA:8 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4688 Set telephone-event payload to 101@8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_media.c:4747 sofia/external/339xxxxxxx@83.xx.xx.xx Set 2833 dtmf send payload to 101 recv payload to 101 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] sofia.c:7471 (sofia/external/339xxxxxxx@83.xx.xx.xx) State Change CS_NEW -> CS_INIT ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_state_machine.c:603 (sofia/external/339xxxxxxx@83.xx.xx.xx) State NEW ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@83.xx.xx.xx) Running State Change CS_INIT (Cur 1 Tot 277) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_state_machine.c:627 (sofia/external/339xxxxxxx@83.xx.xx.xx) State INIT ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] mod_sofia.c:90 sofia/external/339xxxxxxx@83.xx.xx.xx SOFIA INIT ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_state_machine.c:40 sofia/external/339xxxxxxx@83.xx.xx.xx Standard INIT ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_state_machine.c:48 (sofia/external/339xxxxxxx@83.xx.xx.xx) State Change CS_INIT -> CS_ROUTING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_state_machine.c:627 (sofia/external/339xxxxxxx@83.xx.xx.xx) State INIT going to sleep ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@83.xx.xx.xx) Running State Change CS_ROUTING (Cur 1 Tot 277) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_channel.c:2249 (sofia/external/339xxxxxxx@83.xx.xx.xx) Callstate Change DOWN -> RINGING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_state_machine.c:643 (sofia/external/339xxxxxxx@83.xx.xx.xx) State ROUTING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] mod_sofia.c:143 sofia/external/339xxxxxxx@83.xx.xx.xx SOFIA ROUTING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [DEBUG] switch_core_state_machine.c:236 sofia/external/339xxxxxxx@83.xx.xx.xx Standard ROUTING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.627279 [INFO] mod_dialplan_xml.c:637 Processing 339xxxxxxx <339xxxxxxx>->069934xxxx in context public 2017-04-06 17:42:05.787287 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cb4077580 Connected. 2017-04-06 17:42:05.887316 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cb4077580 released. ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [public->Line01Identify] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (PASS) [Line01Identify] destination_number(069934xxxx) =~ /069934xxxx/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action set(call_direction=inbound) INLINE ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(call_direction=inbound) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [call_direction]=[inbound] ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action set(domain_name=83.xx.xx.xx) INLINE ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(domain_name=83.xx.xx.xx) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [domain_name]=[83.xx.xx.xx] ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action set(caller_id_number=01${caller_id_number}) ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [public->0662205304] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [0662205304] destination_number(069934xxxx) =~ /^(0662205304)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [public->0687811330] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [0687811330] destination_number(069934xxxx) =~ /^(0687811330)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [public->069934xxxx] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (PASS) [069934xxxx] destination_number(069934xxxx) =~ /^(069934xxxx)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action set(call_direction=inbound) INLINE ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(call_direction=inbound) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [call_direction]=[inbound] ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action set(domain_uuid=99b281b3-ad75-4f66-8e24-9ec2848ae361) INLINE ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(domain_uuid=99b281b3-ad75-4f66-8e24-9ec2848ae361) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [domain_uuid]=[99b281b3-ad75-4f66-8e24-9ec2848ae361] ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action set(domain_name=192.168.2.10) INLINE ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(domain_name=192.168.2.10) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [domain_name]=[192.168.2.10] ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action lua(call_notify) ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action transfer(310 XML 192.168.2.10) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] switch_core_state_machine.c:286 (sofia/external/339xxxxxxx@83.xx.xx.xx) State Change CS_ROUTING -> CS_EXECUTE ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] switch_core_state_machine.c:643 (sofia/external/339xxxxxxx@83.xx.xx.xx) State ROUTING going to sleep ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@83.xx.xx.xx) Running State Change CS_EXECUTE (Cur 1 Tot 277) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] switch_core_state_machine.c:650 (sofia/external/339xxxxxxx@83.xx.xx.xx) State EXECUTE ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] mod_sofia.c:198 sofia/external/339xxxxxxx@83.xx.xx.xx SOFIA EXECUTE ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] switch_core_state_machine.c:328 sofia/external/339xxxxxxx@83.xx.xx.xx Standard EXECUTE ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(caller_id_number=01339xxxxxxx) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:05.907296 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [caller_id_number]=[01339xxxxxxx] ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx lua(call_notify) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:06.867283 [DEBUG] switch_cpp.cpp:1112 sofia/external/339xxxxxxx@83.xx.xx.xx destroy/unlink session from object ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx transfer(310 XML 192.168.2.10) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:06.867283 [DEBUG] switch_ivr.c:2165 (sofia/external/339xxxxxxx@83.xx.xx.xx) State Change CS_EXECUTE -> CS_ROUTING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:06.867283 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/339xxxxxxx@83.xx.xx.xx to XML[310@192.168.2.10] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:06.867283 [DEBUG] switch_core_state_machine.c:650 (sofia/external/339xxxxxxx@83.xx.xx.xx) State EXECUTE going to sleep ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:06.867283 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@83.xx.xx.xx) Running State Change CS_ROUTING (Cur 1 Tot 277) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:06.867283 [DEBUG] switch_core_state_machine.c:643 (sofia/external/339xxxxxxx@83.xx.xx.xx) State ROUTING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:06.867283 [DEBUG] mod_sofia.c:143 sofia/external/339xxxxxxx@83.xx.xx.xx SOFIA ROUTING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:06.867283 [DEBUG] switch_core_state_machine.c:236 sofia/external/339xxxxxxx@83.xx.xx.xx Standard ROUTING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:06.867283 [INFO] mod_dialplan_xml.c:637 Processing 339xxxxxxx <339xxxxxxx>->310 in context 192.168.2.10 ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->Line01Identify] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [Line01Identify] destination_number(310) =~ /069934xxxx/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->user_exists] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (PASS) [user_exists] () =~ // break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE 2017-04-06 17:42:07.087269 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cb4077580 Connected. 2017-04-06 17:42:07.107322 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cb4077580 released. ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(user_exists=false) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.107322 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [user_exists]=[false] ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->call-direction] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (PASS) [call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->variables] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (PASS) [variables] () =~ // break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action export(origination_callee_id_name=${destination_number}) ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->call_block] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [call_block] ${call_blocked}() =~ /^true$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx ANTI-Action lua(app.lua call_block) ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->user_record] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (PASS) [user_record] () =~ // break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE 2017-04-06 17:42:07.207274 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cb4077580 Connected. 2017-04-06 17:42:07.227280 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cb4077580 released. 2017-04-06 17:42:07.307269 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cb4077580 Connected. 2017-04-06 17:42:07.327280 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cb4077580 released. ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(user_record=) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.327280 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [user_record]=[UNDEF] ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE 2017-04-06 17:42:07.427276 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cb4077580 Connected. 2017-04-06 17:42:07.427276 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cb4077580 released. ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(from_user_exists=false) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.427276 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [from_user_exists]=[false] ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->redial] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [redial] destination_number(310) =~ /^(redial|\*870)$/ break=on-true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (PASS) [redial] () =~ // break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->speed_dial] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [speed_dial] destination_number(310) =~ /^\*0(.*)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->069934xxxx_clouditalia.112113115118] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [069934xxxx_clouditalia.112113115118] destination_number(310) =~ /^(112|113|115|118)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->069934xxxx_clouditalia.096xxxxxxx] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [069934xxxx_clouditalia.096xxxxxxx] destination_number(310) =~ /^(096xxxxxxx)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->069934xxxx_clouditalia.187190] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [069934xxxx_clouditalia.187190] destination_number(310) =~ /^(187|190)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->069934xxxx_clouditalia.800] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [069934xxxx_clouditalia.800] caller_id_name(339xxxxxxx) =~ /^(20|21|200)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->+390644246972_tim.9d] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [+390644246972_tim.9d] destination_number(310) =~ /^9(\d+)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->goose2600.frynga.+39] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [goose2600.frynga.+39] caller_id_number(339xxxxxxx) =~ /^(20|21|200|201)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->goose2600.frynga.INT] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [goose2600.frynga.INT] caller_id_number(339xxxxxxx) =~ /^(20|21|200|201)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->goose2600.frynga.IT] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [goose2600.frynga.IT] caller_id_number(339xxxxxxx) =~ /^(20|21|200|201)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->r.saffi.frynga.INT] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [r.saffi.frynga.INT] caller_id_number(339xxxxxxx) =~ /^(22|23)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->rsaffi.frynga.IT] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [rsaffi.frynga.IT] caller_id_number(339xxxxxxx) =~ /^(22|23)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->agent_status] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [agent_status] destination_number(310) =~ /^\*22$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->agent_status_id] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [agent_status_id] destination_number(310) =~ /^\*23$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->group-intercept] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [group-intercept] destination_number(310) =~ /^\*8$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->page-extension] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [page-extension] destination_number(310) =~ /^\*8(\d{2,7})$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->eavesdrop] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [eavesdrop] destination_number(310) =~ /^\*33(\d{2,7})$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->call_privacy] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [call_privacy] destination_number(310) =~ /^\*67(\d+)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->call_return] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [call_return] destination_number(310) =~ /^\*69$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->extension_queue] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [extension_queue] destination_number(310) =~ /^\*800(.*)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->intercept-ext] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [intercept-ext] destination_number(310) =~ /^\*\*(\d+)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->intercept-ext-polycom] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [intercept-ext-polycom] destination_number(310) =~ /^\*97(\d+)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->dx] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [dx] destination_number(310) =~ /^dx$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->att_xfer] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [att_xfer] destination_number(310) =~ /^att_xfer$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->extension-to-voicemail] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [extension-to-voicemail] ${user_exists}(false) =~ /^true$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->send_to_voicemail] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [send_to_voicemail] destination_number(310) =~ /^\*99(\d{2,10})$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->vmain] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [vmain] destination_number(310) =~ /^vmain$|^\*4000$|^\*98$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->xfer_vm] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [xfer_vm] destination_number(310) =~ /^xfer_vm$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->is_transfer] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [is_transfer] destination_number(310) =~ /^is_transfer$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->vmain_user] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [vmain_user] destination_number(310) =~ /^\*97$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->fabio] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (PASS) [fabio] destination_number(310) =~ /^310$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action lua(call_notify) ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action set(ring_group_uuid=b198104b-1765-4c6c-a912-d4132f1cbdc7) ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Action lua(app.lua ring_groups) ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->genitori] continue= ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [genitori] destination_number(310) =~ /^320$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->cf] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [cf] destination_number(310) =~ /^cf$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->delay_echo] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [delay_echo] destination_number(310) =~ /^\*9195$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->echo] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [echo] destination_number(310) =~ /^\*9196$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->is_zrtp_secure] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [is_zrtp_secure] ${zrtp_secure_media_confirmed}() =~ /^true$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx ANTI-Action eval(not_secure) ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->milliwatt] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [milliwatt] destination_number(310) =~ /^\*9197$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->is_secure] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [is_secure] ${sip_via_protocol}(udp) =~ /tls/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->tone_stream] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [tone_stream] destination_number(310) =~ /^\*9198$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->hold_music] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [hold_music] destination_number(310) =~ /^\*9664$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->recordings] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [recordings] destination_number(310) =~ /^\*(732)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->directory] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [directory] destination_number(310) =~ /^\*411$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->wake-up] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [wake-up] destination_number(310) =~ /^\*(925)$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->valet_park] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [valet_park] destination_number(310) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [valet_park] ${sip_h_Referred-By}() =~ /sip:(.*)@.*/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [valet_park] destination_number(310) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=never ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [valet_park] destination_number(310) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->operator] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [operator] destination_number(310) =~ /^0$|^operator$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->operator-forward] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [operator-forward] destination_number(310) =~ /^\*000$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->do-not-disturb] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [do-not-disturb] destination_number(310) =~ /^\*77$/ break=on-true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [do-not-disturb] destination_number(310) =~ /^\*78$|\*363$/ break=on-true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [do-not-disturb] destination_number(310) =~ /^\*79$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->call-forward] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [call-forward] destination_number(310) =~ /^\*72$/ break=on-true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [call-forward] destination_number(310) =~ /^\*73$/ break=on-true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [call-forward] destination_number(310) =~ /^\*74$/ break=on-true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->follow-me] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [follow-me] destination_number(310) =~ /^\*21$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->clear_sip_auto_answer] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->talking clock date and time] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [talking clock date and time] destination_number(310) =~ /^\*9172$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->talking clock time] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [talking clock time] destination_number(310) =~ /^\*9170$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->talking clock date] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [talking clock date] destination_number(310) =~ /^\*9171$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->call_screen] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [call_screen] ${call_screen_enabled}() =~ /^true$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->200_CALL_NOTFY] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [200_CALL_NOTFY] destination_number(310) =~ /^200$/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->local_extension] continue=true ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [local_extension] ${user_exists}(false) =~ /true/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx parsing [192.168.2.10->voicemail] continue=false ccda4f1e-0f71-4b92-8b37-068702db5e65 Dialplan: sofia/external/339xxxxxxx@83.xx.xx.xx Regex (FAIL) [voicemail] ${user_exists}(false) =~ /true/ break=on-false ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.427276 [DEBUG] switch_core_state_machine.c:286 (sofia/external/339xxxxxxx@83.xx.xx.xx) State Change CS_ROUTING -> CS_EXECUTE ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.427276 [DEBUG] switch_core_state_machine.c:643 (sofia/external/339xxxxxxx@83.xx.xx.xx) State ROUTING going to sleep ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.427276 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@83.xx.xx.xx) Running State Change CS_EXECUTE (Cur 1 Tot 277) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.427276 [DEBUG] switch_core_state_machine.c:650 (sofia/external/339xxxxxxx@83.xx.xx.xx) State EXECUTE ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.427276 [DEBUG] mod_sofia.c:198 sofia/external/339xxxxxxx@83.xx.xx.xx SOFIA EXECUTE ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.427276 [DEBUG] switch_core_state_machine.c:328 sofia/external/339xxxxxxx@83.xx.xx.xx Standard EXECUTE ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx export(origination_callee_id_name=310) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.427276 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[310] ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(RFC2822_DATE=Thu, 06 Apr 2017 17:42:07 +0200) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.427276 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [RFC2822_DATE]=[Thu, 06 Apr 2017 17:42:07 +0200] ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx lua(app.lua call_block) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.447303 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(call_block, ) 2017-04-06 17:42:07.527268 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cb4077580 Connected. 2017-04-06 17:42:07.527268 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cb4077580 released. ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:07.547287 [DEBUG] switch_cpp.cpp:1112 sofia/external/339xxxxxxx@83.xx.xx.xx destroy/unlink session from object ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx hash(insert/192.168.2.10-last_dial/01339xxxxxxx/310) ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx lua(call_notify) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:08.587278 [DEBUG] switch_cpp.cpp:1112 sofia/external/339xxxxxxx@83.xx.xx.xx destroy/unlink session from object ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(ring_group_uuid=b198104b-1765-4c6c-a912-d4132f1cbdc7) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:08.587278 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [ring_group_uuid]=[b198104b-1765-4c6c-a912-d4132f1cbdc7] ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx lua(app.lua ring_groups) 2017-04-06 17:42:08.607301 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cb4077580 Connected. ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx ring_ready() ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:08.607301 [NOTICE] mod_sofia.c:2272 Ring-Ready sofia/external/339xxxxxxx@83.xx.xx.xx! ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:08.607301 [DEBUG] sofia.c:7048 Channel sofia/external/339xxxxxxx@83.xx.xx.xx entering state [early][180] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:08.607301 [NOTICE] mod_dptools.c:1028 Ring Ready sofia/external/339xxxxxxx@83.xx.xx.xx! 2017-04-06 17:42:08.727278 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [200@192.168.2.10] from ip 87.10.10.83 2017-04-06 17:42:09.567279 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [200@192.168.2.10] from ip 87.10.10.83 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:09.807316 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(ringback, tone_stream://%(1000,4000,425);loops=-1) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:09.807316 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(transfer_ringback, tone_stream://%(1000,4000,425);loops=-1) ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(uuids=4ca44427-9ef5-4259-b92b-00bea72e98fb) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:09.807316 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [uuids]=[4ca44427-9ef5-4259-b92b-00bea72e98fb] ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx export(sip_h_Alert-Info=) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:09.807316 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.047270 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(ringback, tone_stream://%(1000,4000,425);loops=-1) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.047270 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(transfer_ringback, tone_stream://%(1000,4000,425);loops=-1) ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(uuids=4ca44427-9ef5-4259-b92b-00bea72e98fb,8a87480c-386c-4181-be20-3ea543d669ef) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.047270 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [uuids]=[4ca44427-9ef5-4259-b92b-00bea72e98fb,8a87480c-386c-4181-be20-3ea543d669ef] ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx export(sip_h_Alert-Info=) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.047270 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.247268 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(ringback, tone_stream://%(1000,4000,425);loops=-1) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.247268 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(transfer_ringback, tone_stream://%(1000,4000,425);loops=-1) ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(uuids=4ca44427-9ef5-4259-b92b-00bea72e98fb,8a87480c-386c-4181-be20-3ea543d669ef,db805cdf-69b2-4d2e-9180-7f855e9772d8) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.267277 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [uuids]=[4ca44427-9ef5-4259-b92b-00bea72e98fb,8a87480c-386c-4181-be20-3ea543d669ef,db805cdf-69b2-4d2e-9180-7f855e9772d8] ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx export(sip_h_Alert-Info=) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.267277 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.487279 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(ringback, tone_stream://%(1000,4000,425);loops=-1) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.487279 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(transfer_ringback, tone_stream://%(1000,4000,425);loops=-1) ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(uuids=4ca44427-9ef5-4259-b92b-00bea72e98fb,8a87480c-386c-4181-be20-3ea543d669ef,db805cdf-69b2-4d2e-9180-7f855e9772d8,9bac078b-f667-4280-91f7-53418179e817) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.487279 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [uuids]=[4ca44427-9ef5-4259-b92b-00bea72e98fb,8a87480c-386c-4181-be20-3ea543d669ef,db805cdf-69b2-4d2e-9180-7f855e9772d8,9bac078b-f667-4280-91f7-53418179e817] ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx export(sip_h_Alert-Info=) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.487279 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF] ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(hangup_after_bridge=true) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.707276 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [hangup_after_bridge]=[true] ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx set(continue_on_fail=true) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.707276 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@83.xx.xx.xx [continue_on_fail]=[true] ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx bind_digit_action(local,*1,exec:execute_extension,dx XML 192.168.2.10,peer) 2017-04-06 17:42:10.707276 [INFO] switch_ivr_async.c:214 Digit parser DPTOOLS: Setting realm to 'local' 2017-04-06 17:42:10.707276 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *1/local/0 callback: 0x7f9ce71a1c20 data: 0x7f9cb40ce5e0 ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx bind_digit_action(local,*2,exec:record_session,/var/lib/freeswitch/recordings/192.168.2.10/archive/2017/Apr/06/ccda4f1e-0f71-4b92-8b37-068702db5e65.wav,peer) 2017-04-06 17:42:10.707276 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *2/local/0 callback: 0x7f9ce71a1c20 data: 0x7f9cb40ce7a8 ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx bind_digit_action(local,*3,exec:execute_extension,cf XML 192.168.2.10,peer) 2017-04-06 17:42:10.707276 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *3/local/0 callback: 0x7f9ce71a1c20 data: 0x7f9cb40ce928 ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx bind_digit_action(local,*4,exec:execute_extension,att_xfer XML 192.168.2.10,peer) 2017-04-06 17:42:10.707276 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *4/local/0 callback: 0x7f9ce71a1c20 data: 0x7f9cb40cea50 ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx digit_action_set_realm(local) 2017-04-06 17:42:10.707276 [NOTICE] switch_cpp.cpp:1365 [ring group] app_data: {sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=20,extension_uuid=3b39609c-50d8-4de9-b45a-01c36fc70113}user/20@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=201,extension_uuid=1a5b6894-006d-4935-b9fb-7185e31e58c6}user/201@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=21,extension_uuid=9f77f7fa-bfb3-4cf6-a29e-d4e7fde2128e}user/21@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=5000,dialed_extension=200,extension_uuid=731cc994-4676-4ba4-a2bc-b2c89f0510e7}user/200@192.168.2.10 ccda4f1e-0f71-4b92-8b37-068702db5e65 EXECUTE sofia/external/339xxxxxxx@83.xx.xx.xx bridge({sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=20,extension_uuid=3b39609c-50d8-4de9-b45a-01c36fc70113}user/20@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=201,extension_uuid=1a5b6894-006d-4935-b9fb-7185e31e58c6}user/201@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=21,extension_uuid=9f77f7fa-bfb3-4cf6-a29e-d4e7fde2128e}user/21@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=5000,dialed_extension=200,extension_uuid=731cc994-4676-4ba4-a2bc-b2c89f0510e7}user/200@192.168.2.10) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.707276 [DEBUG] switch_channel.c:1250 sofia/external/339xxxxxxx@83.xx.xx.xx EXPORTING[export_vars] [origination_callee_id_name]=[310] to event ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.707276 [DEBUG] switch_ivr_originate.c:1548 Parsing ultra-global variables 2017-04-06 17:42:10.707276 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.707276 [INFO] switch_ivr_originate.c:1614 Sending early media 2017-04-06 17:42:10.707276 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2017-04-06 17:42:10.707276 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2017-04-06 17:42:10.707276 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.707276 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/external/339xxxxxxx@83.xx.xx.xx] 192.168.2.10 port 28114 -> 83.211.227.20 port 54776 codec: 8 ms: 20 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.707276 [DEBUG] switch_rtp.c:4095 Starting timer [soft] 160 bytes per 20ms ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.727341 [DEBUG] switch_core_media.c:7109 sofia/external/339xxxxxxx@83.xx.xx.xx Set 2833 dtmf send payload to 101 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.727341 [DEBUG] switch_core_media.c:7116 sofia/external/339xxxxxxx@83.xx.xx.xx Set 2833 dtmf receive payload to 101 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.727341 [DEBUG] switch_core_media.c:7139 sofia/external/339xxxxxxx@83.xx.xx.xx Set rtp dtmf delay to 40 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.727341 [DEBUG] mod_sofia.c:2363 Ring SDP: ccda4f1e-0f71-4b92-8b37-068702db5e65 v=0 ccda4f1e-0f71-4b92-8b37-068702db5e65 o=FreeSWITCH 1491465216 1491465217 IN IP4 87.10.10.83 ccda4f1e-0f71-4b92-8b37-068702db5e65 s=FreeSWITCH ccda4f1e-0f71-4b92-8b37-068702db5e65 c=IN IP4 87.10.10.83 ccda4f1e-0f71-4b92-8b37-068702db5e65 t=0 0 ccda4f1e-0f71-4b92-8b37-068702db5e65 m=audio 28114 RTP/AVP 8 101 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=rtpmap:8 PCMA/8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=rtpmap:101 telephone-event/8000 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=fmtp:101 0-16 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=ptime:20 ccda4f1e-0f71-4b92-8b37-068702db5e65 a=sendrecv ccda4f1e-0f71-4b92-8b37-068702db5e65 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.727341 [NOTICE] mod_sofia.c:2366 Pre-Answer sofia/external/339xxxxxxx@83.xx.xx.xx! ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.727341 [DEBUG] switch_channel.c:3473 (sofia/external/339xxxxxxx@83.xx.xx.xx) Callstate Change RINGING -> EARLY ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.727341 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.727341 [DEBUG] sofia.c:7048 Channel sofia/external/339xxxxxxx@83.xx.xx.xx entering state [early][183] 2017-04-06 17:42:10.827332 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:10.827332 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/20@192.168.77.3:5060 [057d7679-dc5d-4b3a-9090-89c953948239] 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:10.827332 [DEBUG] mod_sofia.c:4818 (sofia/internal/20@192.168.77.3:5060) State Change CS_NEW -> CS_INIT 2017-04-06 17:42:10.827332 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/20@192.168.77.3:5060 Setting leg timeout to 30 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:10.827332 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_INIT (Cur 2 Tot 278) 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:10.827332 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/20@192.168.77.3:5060) State INIT 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:10.827332 [DEBUG] mod_sofia.c:90 sofia/internal/20@192.168.77.3:5060 SOFIA INIT ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:10.887296 [DEBUG] switch_rtp.c:7228 Correct audio ip/port confirmed. 2017-04-06 17:42:10.907292 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:10.907292 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/21@192.168.77.3:5060 [43fcda7f-3610-4388-8d14-e0f724267a6d] 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:10.907292 [DEBUG] mod_sofia.c:4818 (sofia/internal/21@192.168.77.3:5060) State Change CS_NEW -> CS_INIT 2017-04-06 17:42:10.907292 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/21@192.168.77.3:5060 Setting leg timeout to 30 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:10.907292 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_INIT (Cur 3 Tot 279) 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:10.907292 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/21@192.168.77.3:5060) State INIT 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:10.907292 [DEBUG] mod_sofia.c:90 sofia/internal/21@192.168.77.3:5060 SOFIA INIT 2017-04-06 17:42:11.007280 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:11.007280 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/201@87.10.10.83:45862 [e9114a6d-0e02-4cd8-bfcd-8990bd5542d4] e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:11.007280 [DEBUG] mod_sofia.c:4818 (sofia/internal/201@87.10.10.83:45862) State Change CS_NEW -> CS_INIT 2017-04-06 17:42:11.007280 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/201@87.10.10.83:45862 Setting leg timeout to 30 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:11.007280 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_INIT (Cur 4 Tot 280) e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:11.007280 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/201@87.10.10.83:45862) State INIT e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:11.007280 [DEBUG] mod_sofia.c:90 sofia/internal/201@87.10.10.83:45862 SOFIA INIT 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] sofia_glue.c:1264 sip:20@192.168.77.3:5060 Setting proxy route to sofia/internal/20@192.168.77.3:5060 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] sofia_glue.c:1295 sofia/internal/20@192.168.77.3:5060 sending invite version: 1.6.16 -33-e6d643b 64bit 057d7679-dc5d-4b3a-9090-89c953948239 Local SDP: 057d7679-dc5d-4b3a-9090-89c953948239 v=0 057d7679-dc5d-4b3a-9090-89c953948239 o=FreeSWITCH 1491474735 1491474736 IN IP4 87.10.10.83 057d7679-dc5d-4b3a-9090-89c953948239 s=FreeSWITCH 057d7679-dc5d-4b3a-9090-89c953948239 c=IN IP4 87.10.10.83 057d7679-dc5d-4b3a-9090-89c953948239 t=0 0 057d7679-dc5d-4b3a-9090-89c953948239 m=audio 18598 RTP/AVP 9 102 0 8 3 101 13 103 104 057d7679-dc5d-4b3a-9090-89c953948239 a=rtpmap:9 G722/8000 057d7679-dc5d-4b3a-9090-89c953948239 a=rtpmap:102 opus/48000/2 057d7679-dc5d-4b3a-9090-89c953948239 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 057d7679-dc5d-4b3a-9090-89c953948239 a=rtpmap:0 PCMU/8000 057d7679-dc5d-4b3a-9090-89c953948239 a=rtpmap:8 PCMA/8000 057d7679-dc5d-4b3a-9090-89c953948239 a=rtpmap:3 GSM/8000 057d7679-dc5d-4b3a-9090-89c953948239 a=rtpmap:101 telephone-event/8000 057d7679-dc5d-4b3a-9090-89c953948239 a=fmtp:101 0-16 057d7679-dc5d-4b3a-9090-89c953948239 a=rtpmap:103 telephone-event/48000 057d7679-dc5d-4b3a-9090-89c953948239 a=fmtp:103 0-16 057d7679-dc5d-4b3a-9090-89c953948239 a=rtpmap:13 CN/8000 057d7679-dc5d-4b3a-9090-89c953948239 a=rtpmap:104 CN/48000 057d7679-dc5d-4b3a-9090-89c953948239 a=ptime:20 057d7679-dc5d-4b3a-9090-89c953948239 a=sendrecv 057d7679-dc5d-4b3a-9090-89c953948239 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] switch_core_state_machine.c:40 sofia/internal/20@192.168.77.3:5060 Standard INIT 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/20@192.168.77.3:5060) State Change CS_INIT -> CS_ROUTING 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/20@192.168.77.3:5060) State INIT going to sleep 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_ROUTING (Cur 4 Tot 280) 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/20@192.168.77.3:5060) State ROUTING 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] mod_sofia.c:143 sofia/internal/20@192.168.77.3:5060 SOFIA ROUTING 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/20@192.168.77.3:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/20@192.168.77.3:5060) State ROUTING going to sleep 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 280) 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] sofia.c:7048 Channel sofia/internal/20@192.168.77.3:5060 entering state [calling][0] 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/20@192.168.77.3:5060) State CONSUME_MEDIA 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:13.707274 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/20@192.168.77.3:5060) State CONSUME_MEDIA going to sleep 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:14.267270 [DEBUG] sofia.c:7048 Channel sofia/internal/20@192.168.77.3:5060 entering state [proceeding][180] 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:14.267270 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/20@192.168.77.3:5060! 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:14.267270 [DEBUG] switch_channel.c:3345 (sofia/internal/20@192.168.77.3:5060) Callstate Change DOWN -> RINGING 2017-04-06 17:42:14.507273 [NOTICE] sofia_reg.c:448 Registering c6dcb9c2-fee8-4cb1-bfba-f2533911d876 2017-04-06 17:42:14.527275 [DEBUG] sofia_reg.c:2435 Changing expire time to 2845 by request of proxy sip:5.97.153.8:5060 2017-04-06 17:42:15.907275 [DEBUG] switch_nat.c:508 mapped public port 25536 protocol UDP to localport 25536 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] sofia_glue.c:1264 sip:21@192.168.77.3:5060 Setting proxy route to sofia/internal/21@192.168.77.3:5060 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] sofia_glue.c:1295 sofia/internal/21@192.168.77.3:5060 sending invite version: 1.6.16 -33-e6d643b 64bit 43fcda7f-3610-4388-8d14-e0f724267a6d Local SDP: 43fcda7f-3610-4388-8d14-e0f724267a6d v=0 43fcda7f-3610-4388-8d14-e0f724267a6d o=FreeSWITCH 1491467799 1491467800 IN IP4 87.10.10.83 43fcda7f-3610-4388-8d14-e0f724267a6d s=FreeSWITCH 43fcda7f-3610-4388-8d14-e0f724267a6d c=IN IP4 87.10.10.83 43fcda7f-3610-4388-8d14-e0f724267a6d t=0 0 43fcda7f-3610-4388-8d14-e0f724267a6d m=audio 25536 RTP/AVP 9 102 0 8 3 101 13 103 104 43fcda7f-3610-4388-8d14-e0f724267a6d a=rtpmap:9 G722/8000 43fcda7f-3610-4388-8d14-e0f724267a6d a=rtpmap:102 opus/48000/2 43fcda7f-3610-4388-8d14-e0f724267a6d a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 43fcda7f-3610-4388-8d14-e0f724267a6d a=rtpmap:0 PCMU/8000 43fcda7f-3610-4388-8d14-e0f724267a6d a=rtpmap:8 PCMA/8000 43fcda7f-3610-4388-8d14-e0f724267a6d a=rtpmap:3 GSM/8000 43fcda7f-3610-4388-8d14-e0f724267a6d a=rtpmap:101 telephone-event/8000 43fcda7f-3610-4388-8d14-e0f724267a6d a=fmtp:101 0-16 43fcda7f-3610-4388-8d14-e0f724267a6d a=rtpmap:103 telephone-event/48000 43fcda7f-3610-4388-8d14-e0f724267a6d a=fmtp:103 0-16 43fcda7f-3610-4388-8d14-e0f724267a6d a=rtpmap:13 CN/8000 43fcda7f-3610-4388-8d14-e0f724267a6d a=rtpmap:104 CN/48000 43fcda7f-3610-4388-8d14-e0f724267a6d a=ptime:20 43fcda7f-3610-4388-8d14-e0f724267a6d a=sendrecv 43fcda7f-3610-4388-8d14-e0f724267a6d 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] switch_core_state_machine.c:40 sofia/internal/21@192.168.77.3:5060 Standard INIT 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/21@192.168.77.3:5060) State Change CS_INIT -> CS_ROUTING 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/21@192.168.77.3:5060) State INIT going to sleep 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_ROUTING (Cur 4 Tot 280) 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/21@192.168.77.3:5060) State ROUTING 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] mod_sofia.c:143 sofia/internal/21@192.168.77.3:5060 SOFIA ROUTING 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/21@192.168.77.3:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/21@192.168.77.3:5060) State ROUTING going to sleep 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 280) 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] sofia.c:7048 Channel sofia/internal/21@192.168.77.3:5060 entering state [calling][0] 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/21@192.168.77.3:5060) State CONSUME_MEDIA 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:15.907275 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/21@192.168.77.3:5060) State CONSUME_MEDIA going to sleep 2017-04-06 17:42:15.927294 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2017-04-06 17:42:16.007272 [DEBUG] switch_nat.c:508 mapped public port 32304 protocol UDP to localport 32304 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] sofia_glue.c:1295 sofia/internal/201@87.10.10.83:45862 sending invite version: 1.6.16 -33-e6d643b 64bit e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 Local SDP: e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 v=0 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 o=FreeSWITCH 1491461032 1491461033 IN IP4 87.10.10.83 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 s=FreeSWITCH e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 c=IN IP4 87.10.10.83 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 t=0 0 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 m=audio 32304 RTP/AVP 9 102 0 8 3 101 13 103 104 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=rtpmap:9 G722/8000 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=rtpmap:102 opus/48000/2 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=rtpmap:0 PCMU/8000 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=rtpmap:8 PCMA/8000 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=rtpmap:3 GSM/8000 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=rtpmap:101 telephone-event/8000 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=fmtp:101 0-16 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=rtpmap:103 telephone-event/48000 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=fmtp:103 0-16 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=rtpmap:13 CN/8000 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=rtpmap:104 CN/48000 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=ptime:20 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 a=sendrecv e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] switch_core_state_machine.c:40 sofia/internal/201@87.10.10.83:45862 Standard INIT e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/201@87.10.10.83:45862) State Change CS_INIT -> CS_ROUTING e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/201@87.10.10.83:45862) State INIT going to sleep e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_ROUTING (Cur 4 Tot 280) e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/201@87.10.10.83:45862) State ROUTING e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] mod_sofia.c:143 sofia/internal/201@87.10.10.83:45862 SOFIA ROUTING e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/201@87.10.10.83:45862) State Change CS_ROUTING -> CS_CONSUME_MEDIA e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/201@87.10.10.83:45862) State ROUTING going to sleep e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 280) e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] sofia.c:7048 Channel sofia/internal/201@87.10.10.83:45862 entering state [calling][0] e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/201@87.10.10.83:45862) State CONSUME_MEDIA e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:16.007272 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/201@87.10.10.83:45862) State CONSUME_MEDIA going to sleep 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:16.667272 [DEBUG] sofia.c:7048 Channel sofia/internal/21@192.168.77.3:5060 entering state [proceeding][180] 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:16.667272 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/21@192.168.77.3:5060! 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:16.667272 [DEBUG] switch_channel.c:3345 (sofia/internal/21@192.168.77.3:5060) Callstate Change DOWN -> RINGING e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:17.647288 [DEBUG] sofia.c:7048 Channel sofia/internal/201@87.10.10.83:45862 entering state [proceeding][180] e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:17.647288 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/201@87.10.10.83:45862! e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:17.647288 [DEBUG] switch_channel.c:3345 (sofia/internal/201@87.10.10.83:45862) Callstate Change DOWN -> RINGING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.567282 [DEBUG] sofia.c:7048 Channel sofia/external/339xxxxxxx@83.xx.xx.xx entering state [terminated][487] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.567282 [NOTICE] sofia.c:8222 Hangup sofia/external/339xxxxxxx@83.xx.xx.xx [CS_EXECUTE] [ORIGINATOR_CANCEL] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.567282 [DEBUG] switch_ivr_play_say.c:1942 done playing file tone_stream://%(1000,4000,425);loops=-1 2017-04-06 17:42:20.587291 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [user] cause: [NONE] 2017-04-06 17:42:20.587291 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER] e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.587291 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/201@87.10.10.83:45862 [CS_CONSUME_MEDIA] [LOSE_RACE] 2017-04-06 17:42:20.587291 [DEBUG] switch_ivr_originate.c:3822 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.587291 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_HANGUP (Cur 4 Tot 280) 2017-04-06 17:42:20.587291 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [user] cause: [LOSE_RACE] 2017-04-06 17:42:20.587291 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 502 [LOSE_RACE] e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.587291 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/201@87.10.10.83:45862) Callstate Change RINGING -> HANGUP e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.587291 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/201@87.10.10.83:45862) State HANGUP e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.587291 [DEBUG] mod_sofia.c:438 Channel sofia/internal/201@87.10.10.83:45862 hanging up, cause: LOSE_RACE e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.607287 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/201@87.10.10.83:45862 e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:60 sofia/internal/201@87.10.10.83:45862 Standard HANGUP, cause: LOSE_RACE e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/201@87.10.10.83:45862) State HANGUP going to sleep e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/201@87.10.10.83:45862) State Change CS_HANGUP -> CS_REPORTING e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_REPORTING (Cur 4 Tot 280) e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/201@87.10.10.83:45862) State REPORTING 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.607287 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/21@192.168.77.3:5060 [CS_CONSUME_MEDIA] [LOSE_RACE] 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.607287 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/20@192.168.77.3:5060 [CS_CONSUME_MEDIA] [LOSE_RACE] 2017-04-06 17:42:20.607287 [DEBUG] switch_ivr_originate.c:3822 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] 2017-04-06 17:42:20.607287 [DEBUG] switch_ivr_originate.c:3822 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] 2017-04-06 17:42:20.607287 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [user] cause: [LOSE_RACE] 2017-04-06 17:42:20.607287 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 502 [LOSE_RACE] 2017-04-06 17:42:20.607287 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [user] cause: [LOSE_RACE] 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_HANGUP (Cur 4 Tot 280) 2017-04-06 17:42:20.607287 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 502 [LOSE_RACE] 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_HANGUP (Cur 4 Tot 280) 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/20@192.168.77.3:5060) Callstate Change RINGING -> HANGUP 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/20@192.168.77.3:5060) State HANGUP 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.607287 [DEBUG] mod_sofia.c:438 Channel sofia/internal/20@192.168.77.3:5060 hanging up, cause: LOSE_RACE 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/21@192.168.77.3:5060) Callstate Change RINGING -> HANGUP ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [INFO] mod_dptools.c:3418 Originate Failed. Cause: DESTINATION_OUT_OF_ORDER 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/21@192.168.77.3:5060) State HANGUP 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.607287 [DEBUG] mod_sofia.c:438 Channel sofia/internal/21@192.168.77.3:5060 hanging up, cause: LOSE_RACE ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_core_session.c:2814 sofia/external/339xxxxxxx@83.xx.xx.xx skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2017-04-06 17:42:20.607287 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cb4077580 released. ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_cpp.cpp:1112 sofia/external/339xxxxxxx@83.xx.xx.xx destroy/unlink session from object 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.607287 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/20@192.168.77.3:5060 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:60 sofia/internal/20@192.168.77.3:5060 Standard HANGUP, cause: LOSE_RACE 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/20@192.168.77.3:5060) State HANGUP going to sleep 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/20@192.168.77.3:5060) State Change CS_HANGUP -> CS_REPORTING 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_REPORTING (Cur 4 Tot 280) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_core_session.c:2814 sofia/external/339xxxxxxx@83.xx.xx.xx skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:650 (sofia/external/339xxxxxxx@83.xx.xx.xx) State EXECUTE going to sleep ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@83.xx.xx.xx) Running State Change CS_HANGUP (Cur 4 Tot 280) 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/20@192.168.77.3:5060) State REPORTING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:850 (sofia/external/339xxxxxxx@83.xx.xx.xx) Callstate Change EARLY -> HANGUP ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:852 (sofia/external/339xxxxxxx@83.xx.xx.xx) State HANGUP ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] mod_sofia.c:438 Channel sofia/external/339xxxxxxx@83.xx.xx.xx hanging up, cause: ORIGINATOR_CANCEL ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:60 sofia/external/339xxxxxxx@83.xx.xx.xx Standard HANGUP, cause: ORIGINATOR_CANCEL ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:852 (sofia/external/339xxxxxxx@83.xx.xx.xx) State HANGUP going to sleep ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:619 (sofia/external/339xxxxxxx@83.xx.xx.xx) State Change CS_HANGUP -> CS_REPORTING ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@83.xx.xx.xx) Running State Change CS_REPORTING (Cur 4 Tot 280) 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.607287 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/21@192.168.77.3:5060 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:938 (sofia/external/339xxxxxxx@83.xx.xx.xx) State REPORTING 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:60 sofia/internal/21@192.168.77.3:5060 Standard HANGUP, cause: LOSE_RACE 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/21@192.168.77.3:5060) State HANGUP going to sleep 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/21@192.168.77.3:5060) State Change CS_HANGUP -> CS_REPORTING 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_REPORTING (Cur 4 Tot 280) 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.607287 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/21@192.168.77.3:5060) State REPORTING e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.907297 [DEBUG] switch_core_state_machine.c:174 sofia/internal/201@87.10.10.83:45862 Standard REPORTING, cause: LOSE_RACE e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.907297 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/201@87.10.10.83:45862) State REPORTING going to sleep e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.907297 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/201@87.10.10.83:45862) State Change CS_REPORTING -> CS_DESTROY e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.907297 [DEBUG] switch_core_session.c:1664 Session 280 (sofia/internal/201@87.10.10.83:45862) Locked, Waiting on external entities e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.907297 [NOTICE] switch_core_session.c:1682 Session 280 (sofia/internal/201@87.10.10.83:45862) Ended e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.907297 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/201@87.10.10.83:45862 [CS_DESTROY] e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.907297 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_DESTROY (Cur 3 Tot 280) e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.907297 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/201@87.10.10.83:45862) State DESTROY e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:20.907297 [DEBUG] mod_sofia.c:343 sofia/internal/201@87.10.10.83:45862 SOFIA DESTROY 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.947286 [DEBUG] switch_core_state_machine.c:174 sofia/internal/21@192.168.77.3:5060 Standard REPORTING, cause: LOSE_RACE 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.947286 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/21@192.168.77.3:5060) State REPORTING going to sleep 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.947286 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/21@192.168.77.3:5060) State Change CS_REPORTING -> CS_DESTROY 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.947286 [DEBUG] switch_core_session.c:1664 Session 279 (sofia/internal/21@192.168.77.3:5060) Locked, Waiting on external entities 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.947286 [NOTICE] switch_core_session.c:1682 Session 279 (sofia/internal/21@192.168.77.3:5060) Ended 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.947286 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/21@192.168.77.3:5060 [CS_DESTROY] 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.947286 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_DESTROY (Cur 2 Tot 280) 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.947286 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/21@192.168.77.3:5060) State DESTROY 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:20.947286 [DEBUG] mod_sofia.c:343 sofia/internal/21@192.168.77.3:5060 SOFIA DESTROY 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.947286 [DEBUG] switch_core_state_machine.c:174 sofia/internal/20@192.168.77.3:5060 Standard REPORTING, cause: LOSE_RACE 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.947286 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/20@192.168.77.3:5060) State REPORTING going to sleep 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.947286 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/20@192.168.77.3:5060) State Change CS_REPORTING -> CS_DESTROY 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.947286 [DEBUG] switch_core_session.c:1664 Session 278 (sofia/internal/20@192.168.77.3:5060) Locked, Waiting on external entities 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.947286 [NOTICE] switch_core_session.c:1682 Session 278 (sofia/internal/20@192.168.77.3:5060) Ended 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.947286 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/20@192.168.77.3:5060 [CS_DESTROY] 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.947286 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_DESTROY (Cur 1 Tot 280) 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.947286 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/20@192.168.77.3:5060) State DESTROY 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:20.947286 [DEBUG] mod_sofia.c:343 sofia/internal/20@192.168.77.3:5060 SOFIA DESTROY ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:21.187288 [DEBUG] switch_core_state_machine.c:174 sofia/external/339xxxxxxx@83.xx.xx.xx Standard REPORTING, cause: ORIGINATOR_CANCEL ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:21.187288 [DEBUG] switch_core_state_machine.c:938 (sofia/external/339xxxxxxx@83.xx.xx.xx) State REPORTING going to sleep ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:21.187288 [DEBUG] switch_core_state_machine.c:610 (sofia/external/339xxxxxxx@83.xx.xx.xx) State Change CS_REPORTING -> CS_DESTROY ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:21.187288 [DEBUG] switch_core_session.c:1664 Session 277 (sofia/external/339xxxxxxx@83.xx.xx.xx) Locked, Waiting on external entities ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:21.187288 [NOTICE] switch_core_session.c:1682 Session 277 (sofia/external/339xxxxxxx@83.xx.xx.xx) Ended ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:21.187288 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/339xxxxxxx@83.xx.xx.xx [CS_DESTROY] ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:21.207306 [DEBUG] switch_core_state_machine.c:741 (sofia/external/339xxxxxxx@83.xx.xx.xx) Running State Change CS_DESTROY (Cur 0 Tot 280) ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:21.207306 [DEBUG] switch_core_state_machine.c:751 (sofia/external/339xxxxxxx@83.xx.xx.xx) State DESTROY ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:21.207306 [DEBUG] mod_sofia.c:343 sofia/external/339xxxxxxx@83.xx.xx.xx SOFIA DESTROY 2017-04-06 17:42:23.687277 [DEBUG] sofia_reg.c:2435 Changing expire time to 109 by request of proxy sip:callcentric.com e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:23.907281 [DEBUG] switch_core_state_machine.c:181 sofia/internal/201@87.10.10.83:45862 Standard DESTROY e9114a6d-0e02-4cd8-bfcd-8990bd5542d4 2017-04-06 17:42:23.907281 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/201@87.10.10.83:45862) State DESTROY going to sleep 2017-04-06 17:42:25.947283 [DEBUG] switch_nat.c:568 unmapped public port 25536 protocol UDP to localport 25536 2017-04-06 17:42:25.947283 [DEBUG] switch_nat.c:568 unmapped public port 18598 protocol UDP to localport 18598 2017-04-06 17:42:26.207278 [DEBUG] switch_nat.c:568 unmapped public port 28114 protocol UDP to localport 28114 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:26.947280 [DEBUG] switch_core_state_machine.c:181 sofia/internal/21@192.168.77.3:5060 Standard DESTROY 43fcda7f-3610-4388-8d14-e0f724267a6d 2017-04-06 17:42:26.947280 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/21@192.168.77.3:5060) State DESTROY going to sleep 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:29.947274 [DEBUG] switch_core_state_machine.c:181 sofia/internal/20@192.168.77.3:5060 Standard DESTROY 057d7679-dc5d-4b3a-9090-89c953948239 2017-04-06 17:42:29.947274 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/20@192.168.77.3:5060) State DESTROY going to sleep 2017-04-06 17:42:31.207286 [DEBUG] switch_nat.c:568 unmapped public port 28115 protocol UDP to localport 28115 ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:31.207286 [DEBUG] switch_core_state_machine.c:181 sofia/external/339xxxxxxx@83.xx.xx.xx Standard DESTROY ccda4f1e-0f71-4b92-8b37-068702db5e65 2017-04-06 17:42:31.207286 [DEBUG] switch_core_state_machine.c:751 (sofia/external/339xxxxxxx@83.xx.xx.xx) State DESTROY going to sleep 2017-04-06 17:42:31.907280 [DEBUG] sofia_reg.c:2435 Changing expire time to 105 by request of proxy sip:callcentric.com 2017-04-06 17:43:01.547283 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [20@192.168.2.10] from ip 192.168.77.3 2017-04-06 17:43:02.167282 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [21@192.168.2.10] from ip 192.168.77.3 2017-04-06 17:43:02.527272 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [22@192.168.2.10] from ip 192.168.77.3 2017-04-06 17:43:02.887274 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [23@192.168.2.10] from ip 192.168.77.3 2017-04-06 17:43:23.827286 [DEBUG] sofia_reg.c:2435 Changing expire time to 106 by request of proxy sip:callcentric.com b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [NOTICE] switch_channel.c:1104 New Channel sofia/external/339xxxxxxx@62.94.71.96 [b8310f5d-978b-4ecc-8cab-e65a1d2893b0] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@62.94.71.96) Running State Change CS_NEW (Cur 1 Tot 281) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] sofia.c:9825 sofia/external/339xxxxxxx@62.94.71.96 receiving invite from 83.211.227.21:5060 version: 1.6.16 -33-e6d643b 64bit b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] sofia.c:7048 Channel sofia/external/339xxxxxxx@62.94.71.96 entering state [received][100] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] sofia.c:7058 Remote SDP: b8310f5d-978b-4ecc-8cab-e65a1d2893b0 v=0 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 o=CiscoSystemsSIP-GW-UserAgent 7100 716 IN IP4 62.94.71.96 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 s=SIP Call b8310f5d-978b-4ecc-8cab-e65a1d2893b0 c=IN IP4 83.211.227.13 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 t=0 0 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 m=audio 55306 RTP/AVP 18 8 0 4 3 2 125 101 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 c=IN IP4 83.211.227.13 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:18 G729/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=fmtp:18 annexb=yes b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:8 PCMA/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:0 PCMU/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:4 G723/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=fmtp:4 bitrate=5.3;annexa=no b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:3 GSM/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:2 G726-32/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:125 X-CCD/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:101 telephone-event/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=fmtp:101 0-16 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:3889 Activate Buggy RFC2833 Mode! b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G723:4:8000:30:6300:1]/[G722:9:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G723:4:8000:30:6300:1]/[opus:116:48000:20:0:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G723:4:8000:30:6300:1]/[PCMU:0:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G723:4:8000:30:6300:1]/[PCMA:8:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G723:4:8000:30:6300:1]/[GSM:3:8000:20:13200:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [GSM:3:8000:20:13200:1]/[GSM:3:8000:20:13200:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [GSM:3:8000:20:13200:1] ++++ is saved as a match b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G726-32:2:8000:20:0:1]/[G722:9:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G726-32:2:8000:20:0:1]/[opus:116:48000:20:0:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMU:0:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMA:8:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G726-32:2:8000:20:0:1]/[GSM:3:8000:20:13200:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [X-CCD:125:8000:20:0:1]/[G722:9:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [X-CCD:125:8000:20:0:1]/[opus:116:48000:20:0:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [X-CCD:125:8000:20:0:1]/[PCMU:0:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [X-CCD:125:8000:20:0:1]/[PCMA:8:8000:20:64000:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [X-CCD:125:8000:20:0:1]/[GSM:3:8000:20:13200:1] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:3049 Set Codec sofia/external/339xxxxxxx@62.94.71.96 PCMA/8000 20 ms 160 samples 64000 bits 1 channels b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_codec.c:111 sofia/external/339xxxxxxx@62.94.71.96 Original read codec set to PCMA:8 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4688 Set telephone-event payload to 101@8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_media.c:4747 sofia/external/339xxxxxxx@62.94.71.96 Set 2833 dtmf send payload to 101 recv payload to 101 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] sofia.c:7471 (sofia/external/339xxxxxxx@62.94.71.96) State Change CS_NEW -> CS_INIT b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_state_machine.c:603 (sofia/external/339xxxxxxx@62.94.71.96) State NEW b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@62.94.71.96) Running State Change CS_INIT (Cur 1 Tot 281) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_state_machine.c:627 (sofia/external/339xxxxxxx@62.94.71.96) State INIT b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] mod_sofia.c:90 sofia/external/339xxxxxxx@62.94.71.96 SOFIA INIT b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_state_machine.c:40 sofia/external/339xxxxxxx@62.94.71.96 Standard INIT b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_state_machine.c:48 (sofia/external/339xxxxxxx@62.94.71.96) State Change CS_INIT -> CS_ROUTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_state_machine.c:627 (sofia/external/339xxxxxxx@62.94.71.96) State INIT going to sleep b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@62.94.71.96) Running State Change CS_ROUTING (Cur 1 Tot 281) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.687277 [DEBUG] switch_channel.c:2249 (sofia/external/339xxxxxxx@62.94.71.96) Callstate Change DOWN -> RINGING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.707313 [DEBUG] switch_core_state_machine.c:643 (sofia/external/339xxxxxxx@62.94.71.96) State ROUTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.707313 [DEBUG] mod_sofia.c:143 sofia/external/339xxxxxxx@62.94.71.96 SOFIA ROUTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.707313 [DEBUG] switch_core_state_machine.c:236 sofia/external/339xxxxxxx@62.94.71.96 Standard ROUTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.707313 [INFO] mod_dialplan_xml.c:637 Processing 339xxxxxxx <339xxxxxxx>->069934xxxx in context public b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [public->Line01Identify] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (PASS) [Line01Identify] destination_number(069934xxxx) =~ /069934xxxx/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action set(call_direction=inbound) INLINE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(call_direction=inbound) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [call_direction]=[inbound] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action set(domain_name=83.xx.xx.xx) INLINE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(domain_name=83.xx.xx.xx) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [domain_name]=[83.xx.xx.xx] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action set(caller_id_number=01${caller_id_number}) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [public->0662205304] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [0662205304] destination_number(069934xxxx) =~ /^(0662205304)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [public->0687811330] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [0687811330] destination_number(069934xxxx) =~ /^(0687811330)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [public->069934xxxx] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (PASS) [069934xxxx] destination_number(069934xxxx) =~ /^(069934xxxx)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action set(call_direction=inbound) INLINE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(call_direction=inbound) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [call_direction]=[inbound] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action set(domain_uuid=99b281b3-ad75-4f66-8e24-9ec2848ae361) INLINE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(domain_uuid=99b281b3-ad75-4f66-8e24-9ec2848ae361) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [domain_uuid]=[99b281b3-ad75-4f66-8e24-9ec2848ae361] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action set(domain_name=192.168.2.10) INLINE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(domain_name=192.168.2.10) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [domain_name]=[192.168.2.10] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action lua(call_notify) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action transfer(310 XML 192.168.2.10) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] switch_core_state_machine.c:286 (sofia/external/339xxxxxxx@62.94.71.96) State Change CS_ROUTING -> CS_EXECUTE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] switch_core_state_machine.c:643 (sofia/external/339xxxxxxx@62.94.71.96) State ROUTING going to sleep b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@62.94.71.96) Running State Change CS_EXECUTE (Cur 1 Tot 281) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] switch_core_state_machine.c:650 (sofia/external/339xxxxxxx@62.94.71.96) State EXECUTE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] mod_sofia.c:198 sofia/external/339xxxxxxx@62.94.71.96 SOFIA EXECUTE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] switch_core_state_machine.c:328 sofia/external/339xxxxxxx@62.94.71.96 Standard EXECUTE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(caller_id_number=01339xxxxxxx) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:25.807274 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [caller_id_number]=[01339xxxxxxx] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 lua(call_notify) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:26.687283 [DEBUG] switch_cpp.cpp:1112 sofia/external/339xxxxxxx@62.94.71.96 destroy/unlink session from object b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 transfer(310 XML 192.168.2.10) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:26.707279 [DEBUG] switch_ivr.c:2165 (sofia/external/339xxxxxxx@62.94.71.96) State Change CS_EXECUTE -> CS_ROUTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:26.707279 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/339xxxxxxx@62.94.71.96 to XML[310@192.168.2.10] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:26.707279 [DEBUG] switch_core_state_machine.c:650 (sofia/external/339xxxxxxx@62.94.71.96) State EXECUTE going to sleep b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:26.707279 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@62.94.71.96) Running State Change CS_ROUTING (Cur 1 Tot 281) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:26.707279 [DEBUG] switch_core_state_machine.c:643 (sofia/external/339xxxxxxx@62.94.71.96) State ROUTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:26.707279 [DEBUG] mod_sofia.c:143 sofia/external/339xxxxxxx@62.94.71.96 SOFIA ROUTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:26.707279 [DEBUG] switch_core_state_machine.c:236 sofia/external/339xxxxxxx@62.94.71.96 Standard ROUTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:26.707279 [INFO] mod_dialplan_xml.c:637 Processing 339xxxxxxx <339xxxxxxx>->310 in context 192.168.2.10 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->Line01Identify] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [Line01Identify] destination_number(310) =~ /069934xxxx/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->user_exists] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (PASS) [user_exists] () =~ // break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE 2017-04-06 17:43:26.967306 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cc0089b20 Connected. 2017-04-06 17:43:26.967306 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cc0089b20 released. b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(user_exists=false) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:26.967306 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [user_exists]=[false] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->call-direction] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (PASS) [call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->variables] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (PASS) [variables] () =~ // break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action export(origination_callee_id_name=${destination_number}) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->call_block] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [call_block] ${call_blocked}() =~ /^true$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 ANTI-Action lua(app.lua call_block) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->user_record] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (PASS) [user_record] () =~ // break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE 2017-04-06 17:43:27.087307 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cc0089b20 Connected. 2017-04-06 17:43:27.087307 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cc0089b20 released. 2017-04-06 17:43:27.207298 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cc0089b20 Connected. 2017-04-06 17:43:27.207298 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cc0089b20 released. b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(user_record=) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.207298 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [user_record]=[UNDEF] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE 2017-04-06 17:43:27.307279 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cc0089b20 Connected. 2017-04-06 17:43:27.307279 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cc0089b20 released. b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(from_user_exists=false) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.307279 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [from_user_exists]=[false] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->redial] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [redial] destination_number(310) =~ /^(redial|\*870)$/ break=on-true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (PASS) [redial] () =~ // break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->speed_dial] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [speed_dial] destination_number(310) =~ /^\*0(.*)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->069934xxxx_clouditalia.112113115118] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [069934xxxx_clouditalia.112113115118] destination_number(310) =~ /^(112|113|115|118)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->069934xxxx_clouditalia.096xxxxxxx] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [069934xxxx_clouditalia.096xxxxxxx] destination_number(310) =~ /^(096xxxxxxx)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->069934xxxx_clouditalia.187190] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [069934xxxx_clouditalia.187190] destination_number(310) =~ /^(187|190)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->069934xxxx_clouditalia.800] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [069934xxxx_clouditalia.800] caller_id_name(339xxxxxxx) =~ /^(20|21|200)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->+390644246972_tim.9d] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [+390644246972_tim.9d] destination_number(310) =~ /^9(\d+)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->goose2600.frynga.+39] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [goose2600.frynga.+39] caller_id_number(339xxxxxxx) =~ /^(20|21|200|201)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->goose2600.frynga.INT] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [goose2600.frynga.INT] caller_id_number(339xxxxxxx) =~ /^(20|21|200|201)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->goose2600.frynga.IT] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [goose2600.frynga.IT] caller_id_number(339xxxxxxx) =~ /^(20|21|200|201)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->r.saffi.frynga.INT] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [r.saffi.frynga.INT] caller_id_number(339xxxxxxx) =~ /^(22|23)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->rsaffi.frynga.IT] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [rsaffi.frynga.IT] caller_id_number(339xxxxxxx) =~ /^(22|23)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->agent_status] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [agent_status] destination_number(310) =~ /^\*22$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->agent_status_id] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [agent_status_id] destination_number(310) =~ /^\*23$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->group-intercept] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [group-intercept] destination_number(310) =~ /^\*8$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->page-extension] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [page-extension] destination_number(310) =~ /^\*8(\d{2,7})$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->eavesdrop] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [eavesdrop] destination_number(310) =~ /^\*33(\d{2,7})$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->call_privacy] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [call_privacy] destination_number(310) =~ /^\*67(\d+)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->call_return] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [call_return] destination_number(310) =~ /^\*69$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->extension_queue] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [extension_queue] destination_number(310) =~ /^\*800(.*)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->intercept-ext] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [intercept-ext] destination_number(310) =~ /^\*\*(\d+)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->intercept-ext-polycom] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [intercept-ext-polycom] destination_number(310) =~ /^\*97(\d+)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->dx] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [dx] destination_number(310) =~ /^dx$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->att_xfer] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [att_xfer] destination_number(310) =~ /^att_xfer$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->extension-to-voicemail] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [extension-to-voicemail] ${user_exists}(false) =~ /^true$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->send_to_voicemail] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [send_to_voicemail] destination_number(310) =~ /^\*99(\d{2,10})$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->vmain] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [vmain] destination_number(310) =~ /^vmain$|^\*4000$|^\*98$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->xfer_vm] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [xfer_vm] destination_number(310) =~ /^xfer_vm$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->is_transfer] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [is_transfer] destination_number(310) =~ /^is_transfer$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->vmain_user] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [vmain_user] destination_number(310) =~ /^\*97$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->fabio] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (PASS) [fabio] destination_number(310) =~ /^310$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action lua(call_notify) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action set(ring_group_uuid=b198104b-1765-4c6c-a912-d4132f1cbdc7) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Action lua(app.lua ring_groups) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->genitori] continue= b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [genitori] destination_number(310) =~ /^320$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->cf] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [cf] destination_number(310) =~ /^cf$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->delay_echo] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [delay_echo] destination_number(310) =~ /^\*9195$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->echo] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [echo] destination_number(310) =~ /^\*9196$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->is_zrtp_secure] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [is_zrtp_secure] ${zrtp_secure_media_confirmed}() =~ /^true$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 ANTI-Action eval(not_secure) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->milliwatt] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [milliwatt] destination_number(310) =~ /^\*9197$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->is_secure] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [is_secure] ${sip_via_protocol}(udp) =~ /tls/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->tone_stream] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [tone_stream] destination_number(310) =~ /^\*9198$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->hold_music] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [hold_music] destination_number(310) =~ /^\*9664$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->recordings] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [recordings] destination_number(310) =~ /^\*(732)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->directory] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [directory] destination_number(310) =~ /^\*411$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->wake-up] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [wake-up] destination_number(310) =~ /^\*(925)$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->valet_park] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [valet_park] destination_number(310) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [valet_park] ${sip_h_Referred-By}() =~ /sip:(.*)@.*/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [valet_park] destination_number(310) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=never b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [valet_park] destination_number(310) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->operator] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [operator] destination_number(310) =~ /^0$|^operator$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->operator-forward] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [operator-forward] destination_number(310) =~ /^\*000$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->do-not-disturb] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [do-not-disturb] destination_number(310) =~ /^\*77$/ break=on-true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [do-not-disturb] destination_number(310) =~ /^\*78$|\*363$/ break=on-true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [do-not-disturb] destination_number(310) =~ /^\*79$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->call-forward] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [call-forward] destination_number(310) =~ /^\*72$/ break=on-true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [call-forward] destination_number(310) =~ /^\*73$/ break=on-true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [call-forward] destination_number(310) =~ /^\*74$/ break=on-true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->follow-me] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [follow-me] destination_number(310) =~ /^\*21$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->clear_sip_auto_answer] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->talking clock date and time] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [talking clock date and time] destination_number(310) =~ /^\*9172$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->talking clock time] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [talking clock time] destination_number(310) =~ /^\*9170$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->talking clock date] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [talking clock date] destination_number(310) =~ /^\*9171$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->call_screen] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [call_screen] ${call_screen_enabled}() =~ /^true$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->200_CALL_NOTFY] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [200_CALL_NOTFY] destination_number(310) =~ /^200$/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->local_extension] continue=true b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [local_extension] ${user_exists}(false) =~ /true/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 parsing [192.168.2.10->voicemail] continue=false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 Dialplan: sofia/external/339xxxxxxx@62.94.71.96 Regex (FAIL) [voicemail] ${user_exists}(false) =~ /true/ break=on-false b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.327309 [DEBUG] switch_core_state_machine.c:286 (sofia/external/339xxxxxxx@62.94.71.96) State Change CS_ROUTING -> CS_EXECUTE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.327309 [DEBUG] switch_core_state_machine.c:643 (sofia/external/339xxxxxxx@62.94.71.96) State ROUTING going to sleep b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.327309 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@62.94.71.96) Running State Change CS_EXECUTE (Cur 1 Tot 281) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.327309 [DEBUG] switch_core_state_machine.c:650 (sofia/external/339xxxxxxx@62.94.71.96) State EXECUTE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.327309 [DEBUG] mod_sofia.c:198 sofia/external/339xxxxxxx@62.94.71.96 SOFIA EXECUTE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.327309 [DEBUG] switch_core_state_machine.c:328 sofia/external/339xxxxxxx@62.94.71.96 Standard EXECUTE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 export(origination_callee_id_name=310) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.327309 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[310] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(RFC2822_DATE=Thu, 06 Apr 2017 17:43:27 +0200) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.327309 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [RFC2822_DATE]=[Thu, 06 Apr 2017 17:43:27 +0200] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 lua(app.lua call_block) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.327309 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(call_block, ) 2017-04-06 17:43:27.427291 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cc0089b20 Connected. 2017-04-06 17:43:27.427291 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cc0089b20 released. b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:27.427291 [DEBUG] switch_cpp.cpp:1112 sofia/external/339xxxxxxx@62.94.71.96 destroy/unlink session from object b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 hash(insert/192.168.2.10-last_dial/01339xxxxxxx/310) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 lua(call_notify) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:28.267336 [DEBUG] switch_cpp.cpp:1112 sofia/external/339xxxxxxx@62.94.71.96 destroy/unlink session from object b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(ring_group_uuid=b198104b-1765-4c6c-a912-d4132f1cbdc7) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:28.267336 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [ring_group_uuid]=[b198104b-1765-4c6c-a912-d4132f1cbdc7] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 lua(app.lua ring_groups) 2017-04-06 17:43:28.267336 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f9cc0089b20 Connected. b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 ring_ready() b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:28.287285 [NOTICE] mod_sofia.c:2272 Ring-Ready sofia/external/339xxxxxxx@62.94.71.96! b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:28.287285 [DEBUG] sofia.c:7048 Channel sofia/external/339xxxxxxx@62.94.71.96 entering state [early][180] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:28.287285 [NOTICE] mod_dptools.c:1028 Ring Ready sofia/external/339xxxxxxx@62.94.71.96! b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.167277 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(ringback, tone_stream://%(1000,4000,425);loops=-1) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.167277 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(transfer_ringback, tone_stream://%(1000,4000,425);loops=-1) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(uuids=64d07aa2-8d19-43a9-8ec4-ddb9a5d90874) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.167277 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [uuids]=[64d07aa2-8d19-43a9-8ec4-ddb9a5d90874] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 export(sip_h_Alert-Info=) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.167277 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.367267 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(ringback, tone_stream://%(1000,4000,425);loops=-1) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.367267 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(transfer_ringback, tone_stream://%(1000,4000,425);loops=-1) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(uuids=64d07aa2-8d19-43a9-8ec4-ddb9a5d90874,00e0a291-6f5f-40a0-b09a-52baba6677e6) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.367267 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [uuids]=[64d07aa2-8d19-43a9-8ec4-ddb9a5d90874,00e0a291-6f5f-40a0-b09a-52baba6677e6] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 export(sip_h_Alert-Info=) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.387299 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.587317 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(ringback, tone_stream://%(1000,4000,425);loops=-1) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.587317 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(transfer_ringback, tone_stream://%(1000,4000,425);loops=-1) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(uuids=64d07aa2-8d19-43a9-8ec4-ddb9a5d90874,00e0a291-6f5f-40a0-b09a-52baba6677e6,47a52ce9-9957-46c0-8de1-aed5771d3a21) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.587317 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [uuids]=[64d07aa2-8d19-43a9-8ec4-ddb9a5d90874,00e0a291-6f5f-40a0-b09a-52baba6677e6,47a52ce9-9957-46c0-8de1-aed5771d3a21] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 export(sip_h_Alert-Info=) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.587317 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF] 2017-04-06 17:43:29.767277 [DEBUG] sofia_reg.c:2435 Changing expire time to 108 by request of proxy sip:callcentric.com b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.787281 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(ringback, tone_stream://%(1000,4000,425);loops=-1) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.787281 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(transfer_ringback, tone_stream://%(1000,4000,425);loops=-1) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(uuids=64d07aa2-8d19-43a9-8ec4-ddb9a5d90874,00e0a291-6f5f-40a0-b09a-52baba6677e6,47a52ce9-9957-46c0-8de1-aed5771d3a21,736ce701-eb93-4e54-ad47-f795ffa7719b) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.787281 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [uuids]=[64d07aa2-8d19-43a9-8ec4-ddb9a5d90874,00e0a291-6f5f-40a0-b09a-52baba6677e6,47a52ce9-9957-46c0-8de1-aed5771d3a21,736ce701-eb93-4e54-ad47-f795ffa7719b] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 export(sip_h_Alert-Info=) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:29.787281 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(hangup_after_bridge=true) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [hangup_after_bridge]=[true] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 set(continue_on_fail=true) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [DEBUG] mod_dptools.c:1530 SET sofia/external/339xxxxxxx@62.94.71.96 [continue_on_fail]=[true] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 bind_digit_action(local,*1,exec:execute_extension,dx XML 192.168.2.10,peer) 2017-04-06 17:43:30.007282 [INFO] switch_ivr_async.c:214 Digit parser DPTOOLS: Setting realm to 'local' 2017-04-06 17:43:30.007282 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *1/local/0 callback: 0x7f9ce71a1c20 data: 0x7f9cc0030630 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 bind_digit_action(local,*2,exec:record_session,/var/lib/freeswitch/recordings/192.168.2.10/archive/2017/Apr/06/b8310f5d-978b-4ecc-8cab-e65a1d2893b0.wav,peer) 2017-04-06 17:43:30.007282 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *2/local/0 callback: 0x7f9ce71a1c20 data: 0x7f9cc00307f8 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 bind_digit_action(local,*3,exec:execute_extension,cf XML 192.168.2.10,peer) 2017-04-06 17:43:30.007282 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *3/local/0 callback: 0x7f9ce71a1c20 data: 0x7f9cc0030978 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 bind_digit_action(local,*4,exec:execute_extension,att_xfer XML 192.168.2.10,peer) 2017-04-06 17:43:30.007282 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *4/local/0 callback: 0x7f9ce71a1c20 data: 0x7f9cc0030aa0 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 digit_action_set_realm(local) 2017-04-06 17:43:30.007282 [NOTICE] switch_cpp.cpp:1365 [ring group] app_data: {sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=20,extension_uuid=3b39609c-50d8-4de9-b45a-01c36fc70113}user/20@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=201,extension_uuid=1a5b6894-006d-4935-b9fb-7185e31e58c6}user/201@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=21,extension_uuid=9f77f7fa-bfb3-4cf6-a29e-d4e7fde2128e}user/21@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=5000,dialed_extension=200,extension_uuid=731cc994-4676-4ba4-a2bc-b2c89f0510e7}user/200@192.168.2.10 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 EXECUTE sofia/external/339xxxxxxx@62.94.71.96 bridge({sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=20,extension_uuid=3b39609c-50d8-4de9-b45a-01c36fc70113}user/20@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=201,extension_uuid=1a5b6894-006d-4935-b9fb-7185e31e58c6}user/201@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=0,dialed_extension=21,extension_uuid=9f77f7fa-bfb3-4cf6-a29e-d4e7fde2128e}user/21@192.168.2.10:_:{sip_invite_domain=192.168.2.10,call_direction=inbound,confirm=false,leg_timeout=30,originate_delay_start=5000,dialed_extension=200,extension_uuid=731cc994-4676-4ba4-a2bc-b2c89f0510e7}user/200@192.168.2.10) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [DEBUG] switch_channel.c:1250 sofia/external/339xxxxxxx@62.94.71.96 EXPORTING[export_vars] [origination_callee_id_name]=[310] to event b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [DEBUG] switch_ivr_originate.c:1548 Parsing ultra-global variables 2017-04-06 17:43:30.007282 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2017-04-06 17:43:30.007282 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [INFO] switch_ivr_originate.c:1614 Sending early media 2017-04-06 17:43:30.007282 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2017-04-06 17:43:30.007282 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/external/339xxxxxxx@62.94.71.96] 192.168.2.10 port 31930 -> 83.211.227.13 port 55306 codec: 8 ms: 20 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [DEBUG] switch_rtp.c:4095 Starting timer [soft] 160 bytes per 20ms b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [DEBUG] switch_core_media.c:7109 sofia/external/339xxxxxxx@62.94.71.96 Set 2833 dtmf send payload to 101 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [DEBUG] switch_core_media.c:7116 sofia/external/339xxxxxxx@62.94.71.96 Set 2833 dtmf receive payload to 101 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [DEBUG] switch_core_media.c:7139 sofia/external/339xxxxxxx@62.94.71.96 Set rtp dtmf delay to 40 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [DEBUG] mod_sofia.c:2363 Ring SDP: b8310f5d-978b-4ecc-8cab-e65a1d2893b0 v=0 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 o=FreeSWITCH 1491461480 1491461481 IN IP4 87.10.10.83 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 s=FreeSWITCH b8310f5d-978b-4ecc-8cab-e65a1d2893b0 c=IN IP4 87.10.10.83 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 t=0 0 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 m=audio 31930 RTP/AVP 8 101 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:8 PCMA/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:101 telephone-event/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=fmtp:101 0-16 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=ptime:20 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=sendrecv b8310f5d-978b-4ecc-8cab-e65a1d2893b0 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [NOTICE] mod_sofia.c:2366 Pre-Answer sofia/external/339xxxxxxx@62.94.71.96! b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.007282 [DEBUG] switch_channel.c:3473 (sofia/external/339xxxxxxx@62.94.71.96) Callstate Change RINGING -> EARLY b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.027290 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.027290 [DEBUG] sofia.c:7048 Channel sofia/external/339xxxxxxx@62.94.71.96 entering state [early][183] 2017-04-06 17:43:30.107288 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:30.107288 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/21@192.168.77.3:5060 [aad174f8-8786-4a30-87e6-37f1e8c07dc1] aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:30.107288 [DEBUG] mod_sofia.c:4818 (sofia/internal/21@192.168.77.3:5060) State Change CS_NEW -> CS_INIT 2017-04-06 17:43:30.107288 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/21@192.168.77.3:5060 Setting leg timeout to 30 aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:30.107288 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_INIT (Cur 2 Tot 282) aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:30.107288 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/21@192.168.77.3:5060) State INIT aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:30.107288 [DEBUG] mod_sofia.c:90 sofia/internal/21@192.168.77.3:5060 SOFIA INIT 2017-04-06 17:43:30.207326 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:30.207326 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/20@192.168.77.3:5060 [6b487412-d0fe-4ebd-a925-a5e9541fe85a] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:30.207326 [DEBUG] mod_sofia.c:4818 (sofia/internal/20@192.168.77.3:5060) State Change CS_NEW -> CS_INIT 2017-04-06 17:43:30.207326 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/20@192.168.77.3:5060 Setting leg timeout to 30 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:30.207326 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_INIT (Cur 3 Tot 283) 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:30.207326 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/20@192.168.77.3:5060) State INIT 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:30.207326 [DEBUG] mod_sofia.c:90 sofia/internal/20@192.168.77.3:5060 SOFIA INIT b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:30.207326 [DEBUG] switch_rtp.c:7228 Correct audio ip/port confirmed. 2017-04-06 17:43:30.287283 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:30.287283 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/201@87.10.10.83:45862 [6ab87c23-984c-4cd4-9c89-15c276662a86] 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:30.287283 [DEBUG] mod_sofia.c:4818 (sofia/internal/201@87.10.10.83:45862) State Change CS_NEW -> CS_INIT 2017-04-06 17:43:30.287283 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/201@87.10.10.83:45862 Setting leg timeout to 30 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:30.287283 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_INIT (Cur 4 Tot 284) 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:30.287283 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/201@87.10.10.83:45862) State INIT 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:30.287283 [DEBUG] mod_sofia.c:90 sofia/internal/201@87.10.10.83:45862 SOFIA INIT aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] sofia_glue.c:1264 sip:21@192.168.77.3:5060 Setting proxy route to sofia/internal/21@192.168.77.3:5060 aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] sofia_glue.c:1295 sofia/internal/21@192.168.77.3:5060 sending invite version: 1.6.16 -33-e6d643b 64bit aad174f8-8786-4a30-87e6-37f1e8c07dc1 Local SDP: aad174f8-8786-4a30-87e6-37f1e8c07dc1 v=0 aad174f8-8786-4a30-87e6-37f1e8c07dc1 o=FreeSWITCH 1491462395 1491462396 IN IP4 87.10.10.83 aad174f8-8786-4a30-87e6-37f1e8c07dc1 s=FreeSWITCH aad174f8-8786-4a30-87e6-37f1e8c07dc1 c=IN IP4 87.10.10.83 aad174f8-8786-4a30-87e6-37f1e8c07dc1 t=0 0 aad174f8-8786-4a30-87e6-37f1e8c07dc1 m=audio 31018 RTP/AVP 9 102 0 8 3 101 13 103 104 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=rtpmap:9 G722/8000 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=rtpmap:102 opus/48000/2 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=rtpmap:0 PCMU/8000 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=rtpmap:8 PCMA/8000 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=rtpmap:3 GSM/8000 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=rtpmap:101 telephone-event/8000 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=fmtp:101 0-16 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=rtpmap:103 telephone-event/48000 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=fmtp:103 0-16 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=rtpmap:13 CN/8000 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=rtpmap:104 CN/48000 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=ptime:20 aad174f8-8786-4a30-87e6-37f1e8c07dc1 a=sendrecv aad174f8-8786-4a30-87e6-37f1e8c07dc1 aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] switch_core_state_machine.c:40 sofia/internal/21@192.168.77.3:5060 Standard INIT aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/21@192.168.77.3:5060) State Change CS_INIT -> CS_ROUTING aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/21@192.168.77.3:5060) State INIT going to sleep aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_ROUTING (Cur 4 Tot 284) aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/21@192.168.77.3:5060) State ROUTING aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] mod_sofia.c:143 sofia/internal/21@192.168.77.3:5060 SOFIA ROUTING aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/21@192.168.77.3:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/21@192.168.77.3:5060) State ROUTING going to sleep aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 284) aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/21@192.168.77.3:5060) State CONSUME_MEDIA aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/21@192.168.77.3:5060) State CONSUME_MEDIA going to sleep aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.007274 [DEBUG] sofia.c:7048 Channel sofia/internal/21@192.168.77.3:5060 entering state [calling][0] aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.627265 [DEBUG] sofia.c:7048 Channel sofia/internal/21@192.168.77.3:5060 entering state [proceeding][180] aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.627265 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/21@192.168.77.3:5060! aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:33.627265 [DEBUG] switch_channel.c:3345 (sofia/internal/21@192.168.77.3:5060) Callstate Change DOWN -> RINGING 2017-04-06 17:43:35.207285 [DEBUG] switch_nat.c:508 mapped public port 28588 protocol UDP to localport 28588 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] sofia_glue.c:1264 sip:20@192.168.77.3:5060 Setting proxy route to sofia/internal/20@192.168.77.3:5060 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] sofia_glue.c:1295 sofia/internal/20@192.168.77.3:5060 sending invite version: 1.6.16 -33-e6d643b 64bit 6b487412-d0fe-4ebd-a925-a5e9541fe85a Local SDP: 6b487412-d0fe-4ebd-a925-a5e9541fe85a v=0 6b487412-d0fe-4ebd-a925-a5e9541fe85a o=FreeSWITCH 1491464827 1491464828 IN IP4 87.10.10.83 6b487412-d0fe-4ebd-a925-a5e9541fe85a s=FreeSWITCH 6b487412-d0fe-4ebd-a925-a5e9541fe85a c=IN IP4 87.10.10.83 6b487412-d0fe-4ebd-a925-a5e9541fe85a t=0 0 6b487412-d0fe-4ebd-a925-a5e9541fe85a m=audio 28588 RTP/AVP 9 102 0 8 3 101 13 103 104 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=rtpmap:9 G722/8000 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=rtpmap:102 opus/48000/2 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=rtpmap:0 PCMU/8000 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=rtpmap:8 PCMA/8000 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=rtpmap:3 GSM/8000 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=rtpmap:101 telephone-event/8000 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=fmtp:101 0-16 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=rtpmap:103 telephone-event/48000 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=fmtp:103 0-16 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=rtpmap:13 CN/8000 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=rtpmap:104 CN/48000 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=ptime:20 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=sendrecv 6b487412-d0fe-4ebd-a925-a5e9541fe85a 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] switch_core_state_machine.c:40 sofia/internal/20@192.168.77.3:5060 Standard INIT 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/20@192.168.77.3:5060) State Change CS_INIT -> CS_ROUTING 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/20@192.168.77.3:5060) State INIT going to sleep 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_ROUTING (Cur 4 Tot 284) 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/20@192.168.77.3:5060) State ROUTING 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] mod_sofia.c:143 sofia/internal/20@192.168.77.3:5060 SOFIA ROUTING 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/20@192.168.77.3:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/20@192.168.77.3:5060) State ROUTING going to sleep 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 284) 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/20@192.168.77.3:5060) State CONSUME_MEDIA 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/20@192.168.77.3:5060) State CONSUME_MEDIA going to sleep 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:35.207285 [DEBUG] sofia.c:7048 Channel sofia/internal/20@192.168.77.3:5060 entering state [calling][0] 2017-04-06 17:43:35.227307 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2017-04-06 17:43:35.287271 [DEBUG] switch_nat.c:508 mapped public port 26386 protocol UDP to localport 26386 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] sofia_glue.c:1295 sofia/internal/201@87.10.10.83:45862 sending invite version: 1.6.16 -33-e6d643b 64bit 6ab87c23-984c-4cd4-9c89-15c276662a86 Local SDP: 6ab87c23-984c-4cd4-9c89-15c276662a86 v=0 6ab87c23-984c-4cd4-9c89-15c276662a86 o=FreeSWITCH 1491467029 1491467030 IN IP4 87.10.10.83 6ab87c23-984c-4cd4-9c89-15c276662a86 s=FreeSWITCH 6ab87c23-984c-4cd4-9c89-15c276662a86 c=IN IP4 87.10.10.83 6ab87c23-984c-4cd4-9c89-15c276662a86 t=0 0 6ab87c23-984c-4cd4-9c89-15c276662a86 m=audio 26386 RTP/AVP 9 102 0 8 3 101 13 103 104 6ab87c23-984c-4cd4-9c89-15c276662a86 a=rtpmap:9 G722/8000 6ab87c23-984c-4cd4-9c89-15c276662a86 a=rtpmap:102 opus/48000/2 6ab87c23-984c-4cd4-9c89-15c276662a86 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 6ab87c23-984c-4cd4-9c89-15c276662a86 a=rtpmap:0 PCMU/8000 6ab87c23-984c-4cd4-9c89-15c276662a86 a=rtpmap:8 PCMA/8000 6ab87c23-984c-4cd4-9c89-15c276662a86 a=rtpmap:3 GSM/8000 6ab87c23-984c-4cd4-9c89-15c276662a86 a=rtpmap:101 telephone-event/8000 6ab87c23-984c-4cd4-9c89-15c276662a86 a=fmtp:101 0-16 6ab87c23-984c-4cd4-9c89-15c276662a86 a=rtpmap:103 telephone-event/48000 6ab87c23-984c-4cd4-9c89-15c276662a86 a=fmtp:103 0-16 6ab87c23-984c-4cd4-9c89-15c276662a86 a=rtpmap:13 CN/8000 6ab87c23-984c-4cd4-9c89-15c276662a86 a=rtpmap:104 CN/48000 6ab87c23-984c-4cd4-9c89-15c276662a86 a=ptime:20 6ab87c23-984c-4cd4-9c89-15c276662a86 a=sendrecv 6ab87c23-984c-4cd4-9c89-15c276662a86 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] switch_core_state_machine.c:40 sofia/internal/201@87.10.10.83:45862 Standard INIT 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/201@87.10.10.83:45862) State Change CS_INIT -> CS_ROUTING 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/201@87.10.10.83:45862) State INIT going to sleep 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_ROUTING (Cur 4 Tot 284) 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/201@87.10.10.83:45862) State ROUTING 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] mod_sofia.c:143 sofia/internal/201@87.10.10.83:45862 SOFIA ROUTING 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/201@87.10.10.83:45862) State Change CS_ROUTING -> CS_CONSUME_MEDIA 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/201@87.10.10.83:45862) State ROUTING going to sleep 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 284) 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/201@87.10.10.83:45862) State CONSUME_MEDIA 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/201@87.10.10.83:45862) State CONSUME_MEDIA going to sleep 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:35.287271 [DEBUG] sofia.c:7048 Channel sofia/internal/201@87.10.10.83:45862 entering state [calling][0] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:36.207305 [DEBUG] sofia.c:7048 Channel sofia/internal/20@192.168.77.3:5060 entering state [proceeding][180] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:36.207305 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/20@192.168.77.3:5060! 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:36.207305 [DEBUG] switch_channel.c:3345 (sofia/internal/20@192.168.77.3:5060) Callstate Change DOWN -> RINGING 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] sofia.c:7048 Channel sofia/internal/20@192.168.77.3:5060 entering state [completing][200] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] sofia.c:7058 Remote SDP: 6b487412-d0fe-4ebd-a925-a5e9541fe85a v=0 6b487412-d0fe-4ebd-a925-a5e9541fe85a o=20 5008 4 IN IP4 192.168.77.3 6b487412-d0fe-4ebd-a925-a5e9541fe85a s=Mapping 6b487412-d0fe-4ebd-a925-a5e9541fe85a c=IN IP4 192.168.77.3 6b487412-d0fe-4ebd-a925-a5e9541fe85a t=0 0 6b487412-d0fe-4ebd-a925-a5e9541fe85a m=audio 5008 RTP/AVP 9 103 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=rtpmap:9 G722/8000 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=rtpmap:103 telephone-event/8000 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=fmtp:103 0-16 6b487412-d0fe-4ebd-a925-a5e9541fe85a a=ptime:20 6b487412-d0fe-4ebd-a925-a5e9541fe85a 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] sofia.c:7048 Channel sofia/internal/20@192.168.77.3:5060 entering state [ready][200] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 103@8000 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:3049 Set Codec sofia/internal/20@192.168.77.3:5060 G722/8000 20 ms 160 samples 64000 bits 1 channels 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_codec.c:111 sofia/internal/20@192.168.77.3:5060 Original read codec set to G722:9 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:4688 Set telephone-event payload to 103@8000 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:4747 sofia/internal/20@192.168.77.3:5060 Set 2833 dtmf send payload to 103 recv payload to 101 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/internal/20@192.168.77.3:5060] 192.168.2.10 port 28588 -> 192.168.77.3 port 5008 codec: 9 ms: 20 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_rtp.c:4095 Starting timer [soft] 160 bytes per 20ms 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:7109 sofia/internal/20@192.168.77.3:5060 Set 2833 dtmf send payload to 103 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:7116 sofia/internal/20@192.168.77.3:5060 Set 2833 dtmf receive payload to 101 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_core_media.c:7139 sofia/internal/20@192.168.77.3:5060 Set rtp dtmf delay to 40 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [NOTICE] sofia.c:8167 Channel [sofia/internal/20@192.168.77.3:5060] has been answered 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.227267 [DEBUG] switch_channel.c:3772 (sofia/internal/20@192.168.77.3:5060) Callstate Change RINGING -> ACTIVE 2017-04-06 17:43:39.227267 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/20@192.168.77.3:5060] 2017-04-06 17:43:39.247276 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/20@192.168.77.3:5060 Setting leg timeout to 30 2017-04-06 17:43:39.247276 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/20@192.168.77.3:5060] 2017-04-06 17:43:39.247276 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [user] cause: [NONE] 2017-04-06 17:43:39.247276 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER] 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.267285 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/201@87.10.10.83:45862 [CS_CONSUME_MEDIA] [LOSE_RACE] 2017-04-06 17:43:39.267285 [DEBUG] switch_ivr_originate.c:3822 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_HANGUP (Cur 4 Tot 284) 2017-04-06 17:43:39.267285 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [user] cause: [LOSE_RACE] 2017-04-06 17:43:39.267285 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 502 [LOSE_RACE] 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/201@87.10.10.83:45862) Callstate Change DOWN -> HANGUP aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.267285 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/21@192.168.77.3:5060 [CS_CONSUME_MEDIA] [LOSE_RACE] 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/201@87.10.10.83:45862) State HANGUP 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.267285 [DEBUG] mod_sofia.c:438 Channel sofia/internal/201@87.10.10.83:45862 hanging up, cause: LOSE_RACE 2017-04-06 17:43:39.267285 [DEBUG] switch_ivr_originate.c:3822 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_HANGUP (Cur 4 Tot 284) 2017-04-06 17:43:39.267285 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [user] cause: [LOSE_RACE] 2017-04-06 17:43:39.267285 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 502 [LOSE_RACE] 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.267285 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/201@87.10.10.83:45862 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:60 sofia/internal/201@87.10.10.83:45862 Standard HANGUP, cause: LOSE_RACE aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/21@192.168.77.3:5060) Callstate Change RINGING -> HANGUP 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/201@87.10.10.83:45862) State HANGUP going to sleep 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/201@87.10.10.83:45862) State Change CS_HANGUP -> CS_REPORTING aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/21@192.168.77.3:5060) State HANGUP aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.267285 [DEBUG] mod_sofia.c:438 Channel sofia/internal/21@192.168.77.3:5060 hanging up, cause: LOSE_RACE 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_REPORTING (Cur 4 Tot 284) 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/201@87.10.10.83:45862) State REPORTING aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.267285 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/21@192.168.77.3:5060 aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:60 sofia/internal/21@192.168.77.3:5060 Standard HANGUP, cause: LOSE_RACE aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/21@192.168.77.3:5060) State HANGUP going to sleep aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/21@192.168.77.3:5060) State Change CS_HANGUP -> CS_REPORTING aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_REPORTING (Cur 4 Tot 284) aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.267285 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/21@192.168.77.3:5060) State REPORTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:39.267285 [DEBUG] switch_ivr_play_say.c:1942 done playing file tone_stream://%(1000,4000,425);loops=-1 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:39.267285 [DEBUG] switch_core_media.c:6786 Audio params are unchanged for sofia/external/339xxxxxxx@62.94.71.96. b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:39.267285 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/339xxxxxxx@62.94.71.96: b8310f5d-978b-4ecc-8cab-e65a1d2893b0 v=0 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 o=FreeSWITCH 1491461480 1491461482 IN IP4 87.10.10.83 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 s=FreeSWITCH b8310f5d-978b-4ecc-8cab-e65a1d2893b0 c=IN IP4 87.10.10.83 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 t=0 0 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 m=audio 31930 RTP/AVP 8 101 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:8 PCMA/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=rtpmap:101 telephone-event/8000 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=fmtp:101 0-16 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=ptime:20 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 a=sendrecv b8310f5d-978b-4ecc-8cab-e65a1d2893b0 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:39.267285 [NOTICE] switch_ivr_bridge.c:1457 Channel [sofia/external/339xxxxxxx@62.94.71.96] has been answered b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:39.267285 [DEBUG] switch_channel.c:3772 (sofia/external/339xxxxxxx@62.94.71.96) Callstate Change EARLY -> ACTIVE b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:39.267285 [DEBUG] sofia.c:7048 Channel sofia/external/339xxxxxxx@62.94.71.96 entering state [completed][200] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.287306 [DEBUG] switch_ivr_bridge.c:1574 (sofia/internal/20@192.168.77.3:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.287306 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 4 Tot 284) 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.287306 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/20@192.168.77.3:5060) State EXCHANGE_MEDIA 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.287306 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:39.307275 [DEBUG] switch_rtp.c:7228 Correct audio ip/port confirmed. 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:39.307275 [NOTICE] switch_core_io.c:1202 Activating write resampler b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:39.327303 [DEBUG] sofia.c:7048 Channel sofia/external/339xxxxxxx@62.94.71.96 entering state [ready][200] aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.627304 [DEBUG] switch_core_state_machine.c:174 sofia/internal/21@192.168.77.3:5060 Standard REPORTING, cause: LOSE_RACE aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.627304 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/21@192.168.77.3:5060) State REPORTING going to sleep aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.627304 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/21@192.168.77.3:5060) State Change CS_REPORTING -> CS_DESTROY aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.627304 [DEBUG] switch_core_session.c:1664 Session 282 (sofia/internal/21@192.168.77.3:5060) Locked, Waiting on external entities aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.627304 [NOTICE] switch_core_session.c:1682 Session 282 (sofia/internal/21@192.168.77.3:5060) Ended aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.627304 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/21@192.168.77.3:5060 [CS_DESTROY] aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.627304 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/21@192.168.77.3:5060) Running State Change CS_DESTROY (Cur 3 Tot 284) aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.627304 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/21@192.168.77.3:5060) State DESTROY aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:39.627304 [DEBUG] mod_sofia.c:343 sofia/internal/21@192.168.77.3:5060 SOFIA DESTROY 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.667284 [DEBUG] switch_core_state_machine.c:174 sofia/internal/201@87.10.10.83:45862 Standard REPORTING, cause: LOSE_RACE 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.667284 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/201@87.10.10.83:45862) State REPORTING going to sleep 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.667284 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/201@87.10.10.83:45862) State Change CS_REPORTING -> CS_DESTROY 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.667284 [DEBUG] switch_core_session.c:1664 Session 284 (sofia/internal/201@87.10.10.83:45862) Locked, Waiting on external entities 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.667284 [NOTICE] switch_core_session.c:1682 Session 284 (sofia/internal/201@87.10.10.83:45862) Ended 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.667284 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/201@87.10.10.83:45862 [CS_DESTROY] 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.667284 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/201@87.10.10.83:45862) Running State Change CS_DESTROY (Cur 2 Tot 284) 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.667284 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/201@87.10.10.83:45862) State DESTROY 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:39.667284 [DEBUG] mod_sofia.c:343 sofia/internal/201@87.10.10.83:45862 SOFIA DESTROY aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:42.627274 [DEBUG] switch_core_state_machine.c:181 sofia/internal/21@192.168.77.3:5060 Standard DESTROY aad174f8-8786-4a30-87e6-37f1e8c07dc1 2017-04-06 17:43:42.627274 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/21@192.168.77.3:5060) State DESTROY going to sleep 2017-04-06 17:43:44.667270 [DEBUG] switch_nat.c:568 unmapped public port 26386 protocol UDP to localport 26386 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:45.627268 [DEBUG] switch_core_state_machine.c:181 sofia/internal/201@87.10.10.83:45862 Standard DESTROY 6ab87c23-984c-4cd4-9c89-15c276662a86 2017-04-06 17:43:45.627268 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/201@87.10.10.83:45862) State DESTROY going to sleep b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.767274 [DEBUG] switch_ivr_bridge.c:681 sofia/internal/20@192.168.77.3:5060 ending bridge by request from write function b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.767274 [DEBUG] switch_ivr_bridge.c:760 BRIDGE THREAD DONE [sofia/external/339xxxxxxx@62.94.71.96] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.767274 [NOTICE] sofia.c:1012 Hangup sofia/internal/20@192.168.77.3:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.767274 [DEBUG] switch_ivr_bridge.c:1672 sofia/internal/20@192.168.77.3:5060 skip receive message [UNBRIDGE] (channel is hungup already) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.767274 [NOTICE] switch_ivr_bridge.c:1724 Hangup sofia/external/339xxxxxxx@62.94.71.96 [CS_EXECUTE] [NORMAL_CLEARING] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.767274 [DEBUG] switch_ivr_bridge.c:760 BRIDGE THREAD DONE [sofia/internal/20@192.168.77.3:5060] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.767274 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/20@192.168.77.3:5060) State EXCHANGE_MEDIA going to sleep 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.767274 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_HANGUP (Cur 2 Tot 284) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_core_session.c:2814 sofia/external/339xxxxxxx@62.94.71.96 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/20@192.168.77.3:5060) Callstate Change ACTIVE -> HANGUP 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/20@192.168.77.3:5060) State HANGUP 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.787279 [DEBUG] mod_sofia.c:438 Channel sofia/internal/20@192.168.77.3:5060 hanging up, cause: NORMAL_CLEARING 2017-04-06 17:43:47.787279 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f9cc0089b20 released. b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_cpp.cpp:1112 sofia/external/339xxxxxxx@62.94.71.96 destroy/unlink session from object b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_core_session.c:2814 sofia/external/339xxxxxxx@62.94.71.96 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:650 (sofia/external/339xxxxxxx@62.94.71.96) State EXECUTE going to sleep b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@62.94.71.96) Running State Change CS_HANGUP (Cur 2 Tot 284) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:850 (sofia/external/339xxxxxxx@62.94.71.96) Callstate Change ACTIVE -> HANGUP b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:852 (sofia/external/339xxxxxxx@62.94.71.96) State HANGUP b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] mod_sofia.c:432 sofia/external/339xxxxxxx@62.94.71.96 Overriding SIP cause 480 with 200 from the other leg b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] mod_sofia.c:438 Channel sofia/external/339xxxxxxx@62.94.71.96 hanging up, cause: NORMAL_CLEARING 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:60 sofia/internal/20@192.168.77.3:5060 Standard HANGUP, cause: NORMAL_CLEARING 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/20@192.168.77.3:5060) State HANGUP going to sleep 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/20@192.168.77.3:5060) State Change CS_HANGUP -> CS_REPORTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/339xxxxxxx@62.94.71.96 b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:60 sofia/external/339xxxxxxx@62.94.71.96 Standard HANGUP, cause: NORMAL_CLEARING 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_REPORTING (Cur 2 Tot 284) 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/20@192.168.77.3:5060) State REPORTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:852 (sofia/external/339xxxxxxx@62.94.71.96) State HANGUP going to sleep b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:619 (sofia/external/339xxxxxxx@62.94.71.96) State Change CS_HANGUP -> CS_REPORTING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:584 (sofia/external/339xxxxxxx@62.94.71.96) Running State Change CS_REPORTING (Cur 2 Tot 284) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:47.787279 [DEBUG] switch_core_state_machine.c:938 (sofia/external/339xxxxxxx@62.94.71.96) State REPORTING 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:48.127308 [DEBUG] switch_core_state_machine.c:174 sofia/internal/20@192.168.77.3:5060 Standard REPORTING, cause: NORMAL_CLEARING 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:48.127308 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/20@192.168.77.3:5060) State REPORTING going to sleep 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:48.127308 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/20@192.168.77.3:5060) State Change CS_REPORTING -> CS_DESTROY 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:48.127308 [DEBUG] switch_core_session.c:1664 Session 283 (sofia/internal/20@192.168.77.3:5060) Locked, Waiting on external entities 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:48.127308 [NOTICE] switch_core_session.c:1682 Session 283 (sofia/internal/20@192.168.77.3:5060) Ended 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:48.127308 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/20@192.168.77.3:5060 [CS_DESTROY] 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:48.127308 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/20@192.168.77.3:5060) Running State Change CS_DESTROY (Cur 1 Tot 284) 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:48.127308 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/20@192.168.77.3:5060) State DESTROY 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:48.127308 [DEBUG] mod_sofia.c:343 sofia/internal/20@192.168.77.3:5060 SOFIA DESTROY b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:48.147468 [DEBUG] switch_core_state_machine.c:174 sofia/external/339xxxxxxx@62.94.71.96 Standard REPORTING, cause: NORMAL_CLEARING b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:48.147468 [DEBUG] switch_core_state_machine.c:938 (sofia/external/339xxxxxxx@62.94.71.96) State REPORTING going to sleep b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:48.147468 [DEBUG] switch_core_state_machine.c:610 (sofia/external/339xxxxxxx@62.94.71.96) State Change CS_REPORTING -> CS_DESTROY b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:48.147468 [DEBUG] switch_core_session.c:1664 Session 281 (sofia/external/339xxxxxxx@62.94.71.96) Locked, Waiting on external entities b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:48.147468 [NOTICE] switch_core_session.c:1682 Session 281 (sofia/external/339xxxxxxx@62.94.71.96) Ended b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:48.147468 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/339xxxxxxx@62.94.71.96 [CS_DESTROY] b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:48.147468 [DEBUG] switch_core_state_machine.c:741 (sofia/external/339xxxxxxx@62.94.71.96) Running State Change CS_DESTROY (Cur 0 Tot 284) b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:48.147468 [DEBUG] switch_core_state_machine.c:751 (sofia/external/339xxxxxxx@62.94.71.96) State DESTROY b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:48.147468 [DEBUG] mod_sofia.c:343 sofia/external/339xxxxxxx@62.94.71.96 SOFIA DESTROY 2017-04-06 17:43:53.627286 [DEBUG] switch_nat.c:568 unmapped public port 28589 protocol UDP to localport 28589 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:53.627286 [DEBUG] switch_core_state_machine.c:181 sofia/internal/20@192.168.77.3:5060 Standard DESTROY 6b487412-d0fe-4ebd-a925-a5e9541fe85a 2017-04-06 17:43:53.627286 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/20@192.168.77.3:5060) State DESTROY going to sleep b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:54.647270 [DEBUG] switch_core_state_machine.c:181 sofia/external/339xxxxxxx@62.94.71.96 Standard DESTROY b8310f5d-978b-4ecc-8cab-e65a1d2893b0 2017-04-06 17:43:54.647270 [DEBUG] switch_core_state_machine.c:751 (sofia/external/339xxxxxxx@62.94.71.96) State DESTROY going to sleep