2017-02-06 14:38:56.831255 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [0105914600@cvt-fusion.convergedgroup.co.za] from ip 154.118.252.42 61f7bc9f-a328-4f0f-bd21-051e982d4eac 2017-02-06 14:38:56.871234 [INFO] mod_dialplan_xml.c:637 Processing test100 ->0105914600 in context cvt-fusion.convergedgroup.co.za 61f7bc9f-a328-4f0f-bd21-051e982d4eac Dialplan: sofia/internal/cvtmx1@154.118.252.42 Regex (FAIL) [redial] destination_number(0105914600) =~ /^(redial|\*870)$/ break=on-true 61f7bc9f-a328-4f0f-bd21-051e982d4eac Dialplan: sofia/internal/cvtmx1@154.118.252.42 Regex (FAIL) [speed_dial] destination_number(0105914600) =~ /^\*0(.*)$/ break=on-false 61f7bc9f-a328-4f0f-bd21-051e982d4eac Dialplan: sofia/internal/cvtmx1@154.118.252.42 Regex (FAIL) [fusiontest.99d10] destination_number(0105914600) =~ /^99(\d{10})$/ break=on-false 61f7bc9f-a328-4f0f-bd21-051e982d4eac Dialplan: sofia/internal/cvtmx1@154.118.252.42 Regex (PASS) [fusiontest.10d] destination_number(0105914600) =~ /^(\d{10})$/ break=on-false 61f7bc9f-a328-4f0f-bd21-051e982d4eac Dialplan: sofia/internal/cvtmx1@154.118.252.42 Regex (PASS) [fusiontest.10d] destination_number(0105914600) =~ /^(\d{10})$/ break=on-false 61f7bc9f-a328-4f0f-bd21-051e982d4eac Dialplan: sofia/internal/cvtmx1@154.118.252.42 Action bridge(sofia/gateway/13015ebd-ddf3-4e35-8ad5-26d5a8f98484/0105914600) 61f7bc9f-a328-4f0f-bd21-051e982d4eac EXECUTE sofia/internal/cvtmx1@154.118.252.42 export(origination_callee_id_name=0105914600) 61f7bc9f-a328-4f0f-bd21-051e982d4eac 2017-02-06 14:38:56.891231 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[0105914600] 61f7bc9f-a328-4f0f-bd21-051e982d4eac EXECUTE sofia/internal/cvtmx1@154.118.252.42 hash(insert/cvt-fusion.convergedgroup.co.za-last_dial/cvtmx1/0105914600) 61f7bc9f-a328-4f0f-bd21-051e982d4eac EXECUTE sofia/internal/cvtmx1@154.118.252.42 bridge(sofia/gateway/13015ebd-ddf3-4e35-8ad5-26d5a8f98484/0105914600) 61f7bc9f-a328-4f0f-bd21-051e982d4eac 2017-02-06 14:39:02.091241 [DEBUG] switch_channel.c:1250 sofia/internal/cvtmx1@154.118.252.42 EXPORTING[export_vars] [origination_callee_id_name]=[0105914600] to event 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [NOTICE] switch_channel.c:1104 New Channel sofia/external/0105914600 [4014e0f2-f47d-4964-8591-c29cf3c846c0] 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] mod_sofia.c:4808 (sofia/external/0105914600) State Change CS_NEW -> CS_INIT 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_core_state_machine.c:584 (sofia/external/0105914600) Running State Change CS_INIT (Cur 37 Tot 14738) 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_core_state_machine.c:627 (sofia/external/0105914600) State INIT 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] mod_sofia.c:90 sofia/external/0105914600 SOFIA INIT 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] sofia_glue.c:1283 sofia/external/0105914600 sending invite version: 1.6.14 -23-e460bf8 64bit 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_core_state_machine.c:40 sofia/external/0105914600 Standard INIT 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_core_state_machine.c:48 (sofia/external/0105914600) State Change CS_INIT -> CS_ROUTING 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_core_state_machine.c:627 (sofia/external/0105914600) State INIT going to sleep 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_core_state_machine.c:584 (sofia/external/0105914600) Running State Change CS_ROUTING (Cur 37 Tot 14738) 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_core_state_machine.c:643 (sofia/external/0105914600) State ROUTING 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] mod_sofia.c:143 sofia/external/0105914600 SOFIA ROUTING 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_ivr_originate.c:67 (sofia/external/0105914600) State Change CS_ROUTING -> CS_CONSUME_MEDIA 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_core_state_machine.c:643 (sofia/external/0105914600) State ROUTING going to sleep 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_core_state_machine.c:584 (sofia/external/0105914600) Running State Change CS_CONSUME_MEDIA (Cur 37 Tot 14738) 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_core_state_machine.c:662 (sofia/external/0105914600) State CONSUME_MEDIA 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] switch_core_state_machine.c:662 (sofia/external/0105914600) State CONSUME_MEDIA going to sleep 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] sofia.c:7041 Channel sofia/external/0105914600 entering state [calling][0] 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.091241 [DEBUG] sofia.c:7041 Channel sofia/external/0105914600 entering state [calling][0] 2017-02-06 14:39:02.351239 [INFO] sofia.c:1279 sofia/external/0105914600 Update Callee ID to "27105914600" <27105914600> 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.351239 [DEBUG] sofia.c:7041 Channel sofia/external/0105914600 entering state [proceeding][180] 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.351239 [NOTICE] sofia.c:7149 Ring-Ready sofia/external/0105914600! 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:02.351239 [DEBUG] switch_channel.c:3345 (sofia/external/0105914600) Callstate Change DOWN -> RINGING 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [NOTICE] switch_ivr_originate.c:3601 Hangup sofia/external/0105914600 [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL] 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:584 (sofia/external/0105914600) Running State Change CS_HANGUP (Cur 40 Tot 14742) 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:850 (sofia/external/0105914600) Callstate Change RINGING -> HANGUP 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:852 (sofia/external/0105914600) State HANGUP 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] mod_sofia.c:432 sofia/external/0105914600 Overriding SIP cause 487 with 200 from the other leg 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] mod_sofia.c:438 Channel sofia/external/0105914600 hanging up, cause: ORIGINATOR_CANCEL 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/external/0105914600 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:60 sofia/external/0105914600 Standard HANGUP, cause: ORIGINATOR_CANCEL 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:852 (sofia/external/0105914600) State HANGUP going to sleep 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:619 (sofia/external/0105914600) State Change CS_HANGUP -> CS_REPORTING 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:584 (sofia/external/0105914600) Running State Change CS_REPORTING (Cur 40 Tot 14742) 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:938 (sofia/external/0105914600) State REPORTING 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:174 sofia/external/0105914600 Standard REPORTING, cause: ORIGINATOR_CANCEL 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:938 (sofia/external/0105914600) State REPORTING going to sleep 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:610 (sofia/external/0105914600) State Change CS_REPORTING -> CS_DESTROY 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_session.c:1647 Session 14738 (sofia/external/0105914600) Locked, Waiting on external entities 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [NOTICE] switch_core_session.c:1665 Session 14738 (sofia/external/0105914600) Ended 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [NOTICE] switch_core_session.c:1669 Close Channel sofia/external/0105914600 [CS_DESTROY] 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:741 (sofia/external/0105914600) Running State Change CS_DESTROY (Cur 39 Tot 14742) 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:751 (sofia/external/0105914600) State DESTROY 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] mod_sofia.c:343 sofia/external/0105914600 SOFIA DESTROY 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:181 sofia/external/0105914600 Standard DESTROY 4014e0f2-f47d-4964-8591-c29cf3c846c0 2017-02-06 14:39:06.991237 [DEBUG] switch_core_state_machine.c:751 (sofia/external/0105914600) State DESTROY going to sleep ^C