Type /help to see a list of commands +OK log level [7] 2017-05-16 11:41:25.927464 [WARNING] sofia_reg.c:1758 SIP auth challenge (REGISTER) on sofia profile 'internal' for [200@pbx.ripple.jennyme.co.za] from ip 10.19.223.190 2017-05-16 11:41:26.187367 [NOTICE] switch_channel.c:1077 New Channel sofia/internal/106@pbx.probemo.jennyme.co.za [d48288f0-3a1b-11e7-a623-ebab4664731f] 2017-05-16 11:41:26.187367 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/106@pbx.probemo.jennyme.co.za [BREAK] 2017-05-16 11:41:26.187367 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/106@pbx.probemo.jennyme.co.za [BREAK] 2017-05-16 11:41:26.187367 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/106@pbx.probemo.jennyme.co.za) Running State Change CS_NEW 2017-05-16 11:41:26.187367 [DEBUG] sofia.c:8957 sofia/internal/106@pbx.probemo.jennyme.co.za receiving invite from 10.5.126.4:2048 version: 1.4.26 64bit 2017-05-16 11:41:26.187367 [DEBUG] sofia.c:9124 IP 10.5.126.4 Rejected by acl "domains". Falling back to Digest auth. 2017-05-16 11:41:26.187367 [WARNING] sofia_reg.c:1758 SIP auth challenge (INVITE) on sofia profile 'internal' for [00260962200587@pbx.probemo.jennyme.co.za] from ip 10.5.126.4 2017-05-16 11:41:26.187367 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/106@pbx.probemo.jennyme.co.za) State NEW 2017-05-16 11:41:26.187367 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/106@pbx.probemo.jennyme.co.za [BREAK] 2017-05-16 11:41:26.187367 [DEBUG] sofia.c:2065 detaching session d48288f0-3a1b-11e7-a623-ebab4664731f 2017-05-16 11:41:26.247354 [DEBUG] sofia.c:2173 Re-attaching to session d48288f0-3a1b-11e7-a623-ebab4664731f 2017-05-16 11:41:26.247354 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/106@pbx.probemo.jennyme.co.za [BREAK] 2017-05-16 11:41:26.247354 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/106@pbx.probemo.jennyme.co.za [BREAK] 2017-05-16 11:41:26.267339 [DEBUG] sofia.c:8957 sofia/internal/106@pbx.probemo.jennyme.co.za receiving invite from 10.5.126.4:2048 version: 1.4.26 64bit 2017-05-16 11:41:26.267339 [DEBUG] sofia.c:9124 IP 10.5.126.4 Rejected by acl "domains". Falling back to Digest auth. 2017-05-16 11:41:26.267339 [DEBUG] sofia.c:6658 Channel sofia/internal/106@pbx.probemo.jennyme.co.za entering state [received][100] 2017-05-16 11:41:26.267339 [DEBUG] sofia.c:6668 Remote SDP: v=0 o=root 657155282 657155282 IN IP4 10.5.126.4 s=call c=IN IP4 10.5.126.4 t=0 0 m=audio 64300 RTP/AVP 18 8 0 99 3 4 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:99 G726-32/8000 a=rtpmap:3 GSM/8000 a=rtpmap:4 G723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G726-32:99:8000:20:0:1]/[G729:18:8000:20:8000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G726-32:99:8000:20:0:1]/[G722:9:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G726-32:99:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G726-32:99:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G726-32:99:8000:20:0:1]/[GSM:3:8000:20:13200:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G729:18:8000:20:8000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [GSM:3:8000:20:13200:1]/[GSM:3:8000:20:13200:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [GSM:3:8000:20:13200:1] ++++ is saved as a match 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G723:4:8000:20:6300:1]/[G729:18:8000:20:8000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G723:4:8000:20:6300:1]/[G722:9:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMU:0:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMA:8:8000:20:64000:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [G723:4:8000:20:6300:1]/[GSM:3:8000:20:13200:1] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3595 Set telephone-event payload to 101 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:2506 Set Codec sofia/internal/106@pbx.probemo.jennyme.co.za G729/8000 20 ms 160 samples 8000 bits 1 channels 2017-05-16 11:41:26.267339 [DEBUG] switch_core_codec.c:111 sofia/internal/106@pbx.probemo.jennyme.co.za Original read codec set to G729:18 2017-05-16 11:41:26.267339 [DEBUG] switch_core_media.c:3942 Set 2833 dtmf send/recv payload to 101 2017-05-16 11:41:26.267339 [DEBUG] sofia.c:6955 (sofia/internal/106@pbx.probemo.jennyme.co.za) State Change CS_NEW -> CS_INIT 2017-05-16 11:41:26.267339 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/106@pbx.probemo.jennyme.co.za [BREAK] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/106@pbx.probemo.jennyme.co.za) Running State Change CS_INIT 2017-05-16 11:41:26.267339 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/106@pbx.probemo.jennyme.co.za) State INIT 2017-05-16 11:41:26.267339 [DEBUG] mod_sofia.c:87 sofia/internal/106@pbx.probemo.jennyme.co.za SOFIA INIT 2017-05-16 11:41:26.267339 [DEBUG] switch_core_state_machine.c:40 sofia/internal/106@pbx.probemo.jennyme.co.za Standard INIT 2017-05-16 11:41:26.267339 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/106@pbx.probemo.jennyme.co.za) State Change CS_INIT -> CS_ROUTING 2017-05-16 11:41:26.267339 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/106@pbx.probemo.jennyme.co.za [BREAK] 2017-05-16 11:41:26.267339 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/106@pbx.probemo.jennyme.co.za) State INIT going to sleep 2017-05-16 11:41:26.267339 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/106@pbx.probemo.jennyme.co.za) Running State Change CS_ROUTING 2017-05-16 11:41:26.267339 [DEBUG] switch_channel.c:2206 (sofia/internal/106@pbx.probemo.jennyme.co.za) Callstate Change DOWN -> RINGING 2017-05-16 11:41:26.267339 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/106@pbx.probemo.jennyme.co.za) State ROUTING 2017-05-16 11:41:26.267339 [DEBUG] mod_sofia.c:123 sofia/internal/106@pbx.probemo.jennyme.co.za SOFIA ROUTING 2017-05-16 11:41:26.267339 [DEBUG] switch_core_state_machine.c:166 sofia/internal/106@pbx.probemo.jennyme.co.za Standard ROUTING 2017-05-16 11:41:26.267339 [INFO] mod_dialplan_xml.c:635 Processing 106 <106>->00260962200587 in context pbx.probemo.jennyme.co.za Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za parsing [pbx.probemo.jennyme.co.za->user_exists] continue=true Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [user_exists] () =~ // break=on-false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE 2017-05-16 11:41:26.287478 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f8d648c8420 Connected. 2017-05-16 11:41:26.287478 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f8d648c8420 released. EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(user_exists=false) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [user_exists]=[false] Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za parsing [pbx.probemo.jennyme.co.za->call-direction] continue=true Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za ANTI-Action set(call_direction=local) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [call-direction] ${user_exists}(false) =~ /^false$/ break=on-false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [call-direction] destination_number(00260962200587) =~ /^\d{7,20}$/ break=on-false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(call_direction=outbound) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za parsing [pbx.probemo.jennyme.co.za->variables] continue=true Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [variables] () =~ // break=on-false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action export(origination_callee_id_name=${destination_number}) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za parsing [pbx.probemo.jennyme.co.za->user_record] continue=true Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [user_record] () =~ // break=on-false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE 2017-05-16 11:41:26.287478 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f8d648c8420 Connected. 2017-05-16 11:41:26.287478 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f8d648c8420 released. 2017-05-16 11:41:26.287478 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f8d648c8420 Connected. 2017-05-16 11:41:26.287478 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f8d648c8420 released. EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(user_record=) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [user_record]=[UNDEF] Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(from_user_exists=true) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [from_user_exists]=[true] Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(from_user_record=) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [from_user_record]=[UNDEF] Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za parsing [pbx.probemo.jennyme.co.za->redial] continue=true Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [redial] destination_number(00260962200587) =~ /^(redial|\*870)$/ break=on-true Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [redial] () =~ // break=never Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za parsing [pbx.probemo.jennyme.co.za->5444jennyv.10d] continue=false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [5444jennyv.10d] destination_number(00260962200587) =~ /^(\d{10})$/ break=on-false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za parsing [pbx.probemo.jennyme.co.za->5444jennyv.10d] continue=false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (FAIL) [5444jennyv.10d] destination_number(00260962200587) =~ /^(\d{10})$/ break=on-false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za parsing [pbx.probemo.jennyme.co.za->5444jennyv.International] continue=false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Regex (PASS) [5444jennyv.International] destination_number(00260962200587) =~ /^(\d{12,20})$/ break=on-false Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(sip_h_X-accountcode=${accountcode}) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(call_direction=outbound) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(hangup_after_bridge=true) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(effective_caller_id_name=${outbound_caller_id_name}) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(effective_caller_id_number=${outbound_caller_id_number}) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(inherit_codec=true) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(ignore_display_updates=true) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(callee_id_number=00260962200587) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action set(continue_on_fail=true) Dialplan: sofia/internal/106@pbx.probemo.jennyme.co.za Action bridge(sofia/gateway/edec09e1-0920-4adc-848b-7d1683acf58d/00260962200587) 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:216 (sofia/internal/106@pbx.probemo.jennyme.co.za) State Change CS_ROUTING -> CS_EXECUTE 2017-05-16 11:41:26.287478 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/106@pbx.probemo.jennyme.co.za [BREAK] 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/106@pbx.probemo.jennyme.co.za) State ROUTING going to sleep 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/106@pbx.probemo.jennyme.co.za) Running State Change CS_EXECUTE 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/106@pbx.probemo.jennyme.co.za) State EXECUTE 2017-05-16 11:41:26.287478 [DEBUG] mod_sofia.c:178 sofia/internal/106@pbx.probemo.jennyme.co.za SOFIA EXECUTE 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:258 sofia/internal/106@pbx.probemo.jennyme.co.za Standard EXECUTE EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(call_direction=local) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [call_direction]=[local] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(call_direction=outbound) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [call_direction]=[outbound] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za export(origination_callee_id_name=00260962200587) 2017-05-16 11:41:26.287478 [DEBUG] switch_channel.c:1269 EXPORT (export_vars) [origination_callee_id_name]=[00260962200587] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(RFC2822_DATE=Tue, 16 May 2017 11:41:26 +0200) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [RFC2822_DATE]=[Tue, 16 May 2017 11:41:26 +0200] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za hash(insert/pbx.probemo.jennyme.co.za-last_dial/106/00260962200587) EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(sip_h_X-accountcode=pbx.probemo.jennyme.co.za) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [sip_h_X-accountcode]=[pbx.probemo.jennyme.co.za] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(call_direction=outbound) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [call_direction]=[outbound] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(hangup_after_bridge=true) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(effective_caller_id_name=) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [effective_caller_id_name]=[UNDEF] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(effective_caller_id_number=) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [effective_caller_id_number]=[UNDEF] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(inherit_codec=true) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [inherit_codec]=[true] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(ignore_display_updates=true) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [ignore_display_updates]=[true] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(callee_id_number=00260962200587) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [callee_id_number]=[00260962200587] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za set(continue_on_fail=true) 2017-05-16 11:41:26.287478 [DEBUG] mod_dptools.c:1477 sofia/internal/106@pbx.probemo.jennyme.co.za SET [continue_on_fail]=[true] EXECUTE sofia/internal/106@pbx.probemo.jennyme.co.za bridge(sofia/gateway/edec09e1-0920-4adc-848b-7d1683acf58d/00260962200587) 2017-05-16 11:41:26.287478 [DEBUG] switch_channel.c:1223 sofia/internal/106@pbx.probemo.jennyme.co.za EXPORTING[export_vars] [domain_name]=[pbx.probemo.jennyme.co.za] to event 2017-05-16 11:41:26.287478 [DEBUG] switch_channel.c:1223 sofia/internal/106@pbx.probemo.jennyme.co.za EXPORTING[export_vars] [origination_callee_id_name]=[00260962200587] to event 2017-05-16 11:41:26.287478 [DEBUG] switch_ivr_originate.c:2124 Parsing global variables 2017-05-16 11:41:26.287478 [NOTICE] switch_channel.c:1077 New Channel sofia/external/00260962200587 [d4953928-3a1b-11e7-a63b-ebab4664731f] 2017-05-16 11:41:26.287478 [DEBUG] mod_sofia.c:4700 (sofia/external/00260962200587) State Change CS_NEW -> CS_INIT 2017-05-16 11:41:26.287478 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:472 (sofia/external/00260962200587) Running State Change CS_INIT 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:512 (sofia/external/00260962200587) State INIT 2017-05-16 11:41:26.287478 [DEBUG] mod_sofia.c:87 sofia/external/00260962200587 SOFIA INIT 2017-05-16 11:41:26.287478 [DEBUG] sofia_glue.c:1241 sofia/external/00260962200587 sending invite version: 1.4.26 64bit Local SDP: v=0 o=FreeSWITCH 1494910974 1494910975 IN IP4 154.126.201.120 s=FreeSWITCH c=IN IP4 154.126.201.120 t=0 0 m=audio 16712 RTP/AVP 18 0 8 3 101 13 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:40 sofia/external/00260962200587 Standard INIT 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:48 (sofia/external/00260962200587) State Change CS_INIT -> CS_ROUTING 2017-05-16 11:41:26.287478 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:512 (sofia/external/00260962200587) State INIT going to sleep 2017-05-16 11:41:26.287478 [DEBUG] switch_core_session.c:1062 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:472 (sofia/external/00260962200587) Running State Change CS_ROUTING 2017-05-16 11:41:26.287478 [DEBUG] sofia.c:6658 Channel sofia/external/00260962200587 entering state [calling][0] 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:528 (sofia/external/00260962200587) State ROUTING 2017-05-16 11:41:26.287478 [DEBUG] mod_sofia.c:123 sofia/external/00260962200587 SOFIA ROUTING 2017-05-16 11:41:26.287478 [DEBUG] switch_ivr_originate.c:67 (sofia/external/00260962200587) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2017-05-16 11:41:26.287478 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:528 (sofia/external/00260962200587) State ROUTING going to sleep 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:472 (sofia/external/00260962200587) Running State Change CS_CONSUME_MEDIA 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:547 (sofia/external/00260962200587) State CONSUME_MEDIA 2017-05-16 11:41:26.287478 [DEBUG] switch_core_state_machine.c:547 (sofia/external/00260962200587) State CONSUME_MEDIA going to sleep 2017-05-16 11:41:26.287478 [DEBUG] switch_core_session.c:1062 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.287478 [DEBUG] switch_core_session.c:1062 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.287478 [DEBUG] sofia.c:6658 Channel sofia/external/00260962200587 entering state [calling][0] 2017-05-16 11:41:26.327336 [NOTICE] switch_channel.c:1077 New Channel sofia/internal/117@pbx.sizwe.jennyme.co.za:5060 [d4987eee-3a1b-11e7-a63f-ebab4664731f] 2017-05-16 11:41:26.327336 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/117@pbx.sizwe.jennyme.co.za:5060 [BREAK] 2017-05-16 11:41:26.327336 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/117@pbx.sizwe.jennyme.co.za:5060 [BREAK] 2017-05-16 11:41:26.327336 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/117@pbx.sizwe.jennyme.co.za:5060) Running State Change CS_NEW 2017-05-16 11:41:26.327336 [DEBUG] sofia.c:8957 sofia/internal/117@pbx.sizwe.jennyme.co.za:5060 receiving invite from 154.126.209.220:1290 version: 1.4.26 64bit 2017-05-16 11:41:26.327336 [DEBUG] sofia.c:9124 IP 154.126.209.220 Rejected by acl "domains". Falling back to Digest auth. 2017-05-16 11:41:26.327336 [WARNING] sofia_reg.c:1758 SIP auth challenge (INVITE) on sofia profile 'internal' for [0727958573@pbx.sizwe.jennyme.co.za] from ip 154.126.209.220 2017-05-16 11:41:26.327336 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/117@pbx.sizwe.jennyme.co.za:5060) State NEW 2017-05-16 11:41:26.327336 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/117@pbx.sizwe.jennyme.co.za:5060 [BREAK] 2017-05-16 11:41:26.327336 [DEBUG] sofia.c:2065 detaching session d4987eee-3a1b-11e7-a63f-ebab4664731f 2017-05-16 11:41:26.347350 [DEBUG] switch_core_session.c:1062 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.347350 [DEBUG] switch_core_session.c:1062 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.347350 [DEBUG] switch_core_session.c:1062 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.367338 [DEBUG] sofia.c:6658 Channel sofia/external/00260962200587 entering state [terminated][503] 2017-05-16 11:41:26.367338 [NOTICE] sofia.c:7580 Hangup sofia/external/00260962200587 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2017-05-16 11:41:26.367338 [DEBUG] switch_channel.c:3244 Send signal sofia/external/00260962200587 [KILL] 2017-05-16 11:41:26.367338 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:472 (sofia/external/00260962200587) Running State Change CS_HANGUP 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:735 (sofia/external/00260962200587) Callstate Change DOWN -> HANGUP 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:737 (sofia/external/00260962200587) State HANGUP 2017-05-16 11:41:26.367338 [DEBUG] mod_sofia.c:413 Channel sofia/external/00260962200587 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:60 sofia/external/00260962200587 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:737 (sofia/external/00260962200587) State HANGUP going to sleep 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:504 (sofia/external/00260962200587) State Change CS_HANGUP -> CS_REPORTING 2017-05-16 11:41:26.367338 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:472 (sofia/external/00260962200587) Running State Change CS_REPORTING 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:823 (sofia/external/00260962200587) State REPORTING 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:104 sofia/external/00260962200587 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:823 (sofia/external/00260962200587) State REPORTING going to sleep 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:498 (sofia/external/00260962200587) State Change CS_REPORTING -> CS_DESTROY 2017-05-16 11:41:26.367338 [DEBUG] switch_core_session.c:1397 Send signal sofia/external/00260962200587 [BREAK] 2017-05-16 11:41:26.367338 [DEBUG] switch_core_session.c:1624 Session 20683 (sofia/external/00260962200587) Locked, Waiting on external entities 2017-05-16 11:41:26.367338 [DEBUG] switch_ivr_originate.c:3747 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2017-05-16 11:41:26.367338 [NOTICE] switch_core_session.c:1642 Session 20683 (sofia/external/00260962200587) Ended 2017-05-16 11:41:26.367338 [NOTICE] switch_core_session.c:1646 Close Channel sofia/external/00260962200587 [CS_DESTROY] 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:626 (sofia/external/00260962200587) Running State Change CS_DESTROY 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:636 (sofia/external/00260962200587) State DESTROY 2017-05-16 11:41:26.367338 [DEBUG] mod_sofia.c:323 sofia/external/00260962200587 SOFIA DESTROY 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:111 sofia/external/00260962200587 Standard DESTROY 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:636 (sofia/external/00260962200587) State DESTROY going to sleep 2017-05-16 11:41:26.367338 [INFO] mod_dptools.c:3276 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2017-05-16 11:41:26.367338 [NOTICE] switch_core_state_machine.c:315 sofia/internal/106@pbx.probemo.jennyme.co.za has executed the last dialplan instruction, hanging up. 2017-05-16 11:41:26.367338 [NOTICE] switch_core_state_machine.c:317 Hangup sofia/internal/106@pbx.probemo.jennyme.co.za [CS_EXECUTE] [NORMAL_CLEARING] 2017-05-16 11:41:26.367338 [DEBUG] switch_channel.c:3244 Send signal sofia/internal/106@pbx.probemo.jennyme.co.za [KILL] 2017-05-16 11:41:26.367338 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/106@pbx.probemo.jennyme.co.za [BREAK] 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/106@pbx.probemo.jennyme.co.za) State EXECUTE going to sleep 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/106@pbx.probemo.jennyme.co.za) Running State Change CS_HANGUP 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/106@pbx.probemo.jennyme.co.za) Callstate Change RINGING -> HANGUP 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/106@pbx.probemo.jennyme.co.za) State HANGUP 2017-05-16 11:41:26.367338 [DEBUG] mod_sofia.c:407 sofia/internal/106@pbx.probemo.jennyme.co.za Overriding SIP cause 480 with 503 from the other leg 2017-05-16 11:41:26.367338 [DEBUG] mod_sofia.c:413 Channel sofia/internal/106@pbx.probemo.jennyme.co.za hanging up, cause: NORMAL_CLEARING 2017-05-16 11:41:26.367338 [DEBUG] mod_sofia.c:549 Responding to INVITE with: 503 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:60 sofia/internal/106@pbx.probemo.jennyme.co.za Standard HANGUP, cause: NORMAL_CLEARING 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/106@pbx.probemo.jennyme.co.za) State HANGUP going to sleep 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/106@pbx.probemo.jennyme.co.za) State Change CS_HANGUP -> CS_REPORTING 2017-05-16 11:41:26.367338 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/106@pbx.probemo.jennyme.co.za [BREAK] 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/106@pbx.probemo.jennyme.co.za) Running State Change CS_REPORTING 2017-05-16 11:41:26.367338 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/106@pbx.probemo.jennyme.co.za) State REPORTING