c25a4bfa-4521-474d-b920-b2ba402022cb 2017-02-06 14:56:13.211243 [DEBUG] switch_core_media.c:6703 AUDIO RTP [sofia/internal/101@10.10.11.101:5060] 154.118.252.39 port 21026 -> 10.10.11.101 port 12632 codec: 18 ms: 20 2017-02-06 14:56:18.851234 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [1026@cvt-fusion.convergedgroup.co.za] from ip 10.192.0.82 795f9814-5de4-4ea9-ac8e-ae5e19b08460 2017-02-06 14:56:19.191238 [INFO] mod_dialplan_xml.c:637 Processing cvtmx1 ->1026 in context cvt-fusion.convergedgroup.co.za 795f9814-5de4-4ea9-ac8e-ae5e19b08460 Dialplan: sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za Regex (FAIL) [redial] destination_number(1026) =~ /^(redial|\*870)$/ break=on-true 795f9814-5de4-4ea9-ac8e-ae5e19b08460 Dialplan: sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za Regex (FAIL) [speed_dial] destination_number(1026) =~ /^\*0(.*)$/ break=on-false 795f9814-5de4-4ea9-ac8e-ae5e19b08460 Dialplan: sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za Regex (FAIL) [fusiontest.10d] destination_number(1026) =~ /^(\d{10})$/ break=on-false 795f9814-5de4-4ea9-ac8e-ae5e19b08460 Dialplan: sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za Regex (PASS) [fusiontest.d4] destination_number(1026) =~ /^(\d{4})$/ break=on-false 795f9814-5de4-4ea9-ac8e-ae5e19b08460 Dialplan: sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za Action set(callee_id_number=1026) 795f9814-5de4-4ea9-ac8e-ae5e19b08460 Dialplan: sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za Action bridge(sofia/gateway/13015ebd-ddf3-4e35-8ad5-26d5a8f98484/1026) 795f9814-5de4-4ea9-ac8e-ae5e19b08460 EXECUTE sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za export(origination_callee_id_name=1026) 795f9814-5de4-4ea9-ac8e-ae5e19b08460 2017-02-06 14:56:19.231235 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[1026] 795f9814-5de4-4ea9-ac8e-ae5e19b08460 EXECUTE sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za hash(insert/cvt-fusion.convergedgroup.co.za-last_dial/cvtmx1/1026) 795f9814-5de4-4ea9-ac8e-ae5e19b08460 EXECUTE sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za set(RECORD_TITLE=Recording 1026 cvtmx1 2017-02-06 14:56) 795f9814-5de4-4ea9-ac8e-ae5e19b08460 2017-02-06 14:56:19.231235 [DEBUG] mod_dptools.c:1527 SET sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za [RECORD_TITLE]=[Recording 1026 cvtmx1 2017-02-06 14:56] 795f9814-5de4-4ea9-ac8e-ae5e19b08460 EXECUTE sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za record_session(/var/lib/freeswitch/recordings/archive/2017/Feb/06/_1026_cvtmx1_2017-02-06 14:56.mp3) 795f9814-5de4-4ea9-ac8e-ae5e19b08460 EXECUTE sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za set(callee_id_number=1026) 795f9814-5de4-4ea9-ac8e-ae5e19b08460 2017-02-06 14:56:19.251239 [DEBUG] mod_dptools.c:1527 SET sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za [callee_id_number]=[1026] 795f9814-5de4-4ea9-ac8e-ae5e19b08460 EXECUTE sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za bridge(sofia/gateway/13015ebd-ddf3-4e35-8ad5-26d5a8f98484/1026) 795f9814-5de4-4ea9-ac8e-ae5e19b08460 2017-02-06 14:56:19.251239 [DEBUG] switch_channel.c:1250 sofia/internal/cvtmx1@cvt-fusion.convergedgroup.co.za EXPORTING[export_vars] [origination_callee_id_name]=[1026] to event bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [NOTICE] switch_channel.c:1104 New Channel sofia/external/1026 [bfed2d14-31b9-46f1-903e-aaf048b652ae] bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] mod_sofia.c:4808 (sofia/external/1026) State Change CS_NEW -> CS_INIT bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1026) Running State Change CS_INIT (Cur 32 Tot 15151) bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1026) State INIT bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] mod_sofia.c:90 sofia/external/1026 SOFIA INIT bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] sofia_glue.c:1283 sofia/external/1026 sending invite version: 1.6.14 -23-e460bf8 64bit bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_core_state_machine.c:40 sofia/external/1026 Standard INIT bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_core_state_machine.c:48 (sofia/external/1026) State Change CS_INIT -> CS_ROUTING bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1026) State INIT going to sleep bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1026) Running State Change CS_ROUTING (Cur 32 Tot 15151) bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] sofia.c:7041 Channel sofia/external/1026 entering state [calling][0] bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1026) State ROUTING bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] mod_sofia.c:143 sofia/external/1026 SOFIA ROUTING bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_ivr_originate.c:67 (sofia/external/1026) State Change CS_ROUTING -> CS_CONSUME_MEDIA bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1026) State ROUTING going to sleep bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1026) Running State Change CS_CONSUME_MEDIA (Cur 32 Tot 15151) bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1026) State CONSUME_MEDIA bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1026) State CONSUME_MEDIA going to sleep bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:19.251239 [DEBUG] sofia.c:7041 Channel sofia/external/1026 entering state [calling][0] bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.751237 [DEBUG] sofia.c:7041 Channel sofia/external/1026 entering state [proceeding][183] bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.751237 [DEBUG] switch_core_media.c:3043 Set Codec sofia/external/1026 G729/8000 20 ms 160 samples 8000 bits 1 channels bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.751237 [DEBUG] switch_core_codec.c:111 sofia/external/1026 Original read codec set to G729:18 bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.751237 [DEBUG] switch_core_media.c:4696 sofia/external/1026 Set 2833 dtmf send payload to 101 recv payload to 101 bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.751237 [DEBUG] switch_core_media.c:6703 AUDIO RTP [sofia/external/1026] 154.118.252.39 port 29216 -> 154.118.252.43 port 12750 codec: 18 ms: 20 bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.751237 [DEBUG] switch_core_media.c:7009 sofia/external/1026 Set 2833 dtmf send payload to 101 bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.751237 [DEBUG] switch_core_media.c:7016 sofia/external/1026 Set 2833 dtmf receive payload to 101 bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.751237 [DEBUG] switch_core_media.c:7039 sofia/external/1026 Set rtp dtmf delay to 40 bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.751237 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/1026! bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.751237 [DEBUG] switch_channel.c:3473 (sofia/external/1026) Callstate Change DOWN -> EARLY 795f9814-5de4-4ea9-ac8e-ae5e19b08460 2017-02-06 14:56:34.771237 [DEBUG] switch_ivr_originate.c:3686 Originate Resulted in Success: [sofia/external/1026] bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.771237 [DEBUG] switch_ivr_bridge.c:1566 (sofia/external/1026) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.771237 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1026) Running State Change CS_EXCHANGE_MEDIA (Cur 36 Tot 15164) bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.771237 [DEBUG] switch_core_state_machine.c:653 (sofia/external/1026) State EXCHANGE_MEDIA bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.811245 [DEBUG] sofia.c:7041 Channel sofia/external/1026 entering state [completing][200] bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.831249 [DEBUG] sofia.c:7041 Channel sofia/external/1026 entering state [ready][200] bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.831249 [NOTICE] sofia.c:8098 Channel [sofia/external/1026] has been answered bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.831249 [DEBUG] switch_channel.c:3570 sofia/external/1026 process uuid_record 795f9814-5de4-4ea9-ac8e-ae5e19b08460 start /var/lib/freeswitch/recordings/cvt-fusion.convergedgroup.co.za/archive/2017/Feb/06/795f9814-5de4-4ea9-ac8e-ae5e19b08460.mp3: uuid_record(795f9814-5de4-4ea9-ac8e-ae5e19b08460 start /var/lib/freeswitch/recordings/cvt-fusion.convergedgroup.co.za/archive/2017/Feb/06/795f9814-5de4-4ea9-ac8e-ae5e19b08460.mp3) bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:34.851239 [DEBUG] switch_channel.c:3772 (sofia/external/1026) Callstate Change EARLY -> ACTIVE bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_ivr_bridge.c:752 BRIDGE THREAD DONE [sofia/external/1026] bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [NOTICE] switch_ivr_bridge.c:856 Hangup sofia/external/1026 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:653 (sofia/external/1026) State EXCHANGE_MEDIA going to sleep bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1026) Running State Change CS_HANGUP (Cur 34 Tot 15164) bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:850 (sofia/external/1026) Callstate Change ACTIVE -> HANGUP bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1026) State HANGUP bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] mod_sofia.c:432 sofia/external/1026 Overriding SIP cause 480 with 200 from the other leg bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] mod_sofia.c:438 Channel sofia/external/1026 hanging up, cause: NORMAL_CLEARING bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/1026 bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:60 sofia/external/1026 Standard HANGUP, cause: NORMAL_CLEARING bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1026) State HANGUP going to sleep bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:619 (sofia/external/1026) State Change CS_HANGUP -> CS_REPORTING bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1026) Running State Change CS_REPORTING (Cur 34 Tot 15164) bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1026) State REPORTING bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:174 sofia/external/1026 Standard REPORTING, cause: NORMAL_CLEARING bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1026) State REPORTING going to sleep bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_ivr_bridge.c:1664 sofia/external/1026 skip receive message [UNBRIDGE] (channel is hungup already) bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:610 (sofia/external/1026) State Change CS_REPORTING -> CS_DESTROY bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_session.c:1647 Session 15151 (sofia/external/1026) Locked, Waiting on external entities bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [NOTICE] switch_core_session.c:1665 Session 15151 (sofia/external/1026) Ended bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [NOTICE] switch_core_session.c:1669 Close Channel sofia/external/1026 [CS_DESTROY] bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:741 (sofia/external/1026) Running State Change CS_DESTROY (Cur 33 Tot 15164) bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1026) State DESTROY bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] mod_sofia.c:343 sofia/external/1026 SOFIA DESTROY bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:181 sofia/external/1026 Standard DESTROY bfed2d14-31b9-46f1-903e-aaf048b652ae 2017-02-06 14:56:38.491242 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1026) State DESTROY going to sleep 795f9814-5de4-4ea9-ac8e-ae5e19b08460 2017-02-06 14:56:38.511243 [DEBUG] switch_ivr_async.c:1312 Stop recording file /var/lib/freeswitch/recordings/archive/2017/Feb/06/_1026_cvtmx1_2017-02-06 14:56.mp3