2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 8215408144 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Balance : 268.5196 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 0 [0:prepaid,1:postpaid] 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 1 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] ======================================================== 2018-12-13 14:23:19.855019 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0 2018-12-13 14:23:19.855019 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,B.id as accountid,B.number as account_code,B.did_cid_translation as did_cid_translation,A.number as did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout FROM dids AS A,accounts AS B WHERE A.status=0 AND B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="3211177971" LIMIT 1 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 100 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information =================== 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 2 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Code : ^.3211177971.* 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Destination : 3211177971 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0.00000 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 0.00000 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Initial Increment : 0 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Increment : 0 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 5 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================ 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Call Max length duration : 100 minutes 2018-12-13 14:23:19.855019 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE (number = "5" OR id="5") AND status=0 AND deleted=0 AND (expiry >= '2018-12-13 13:24:22' OR expiry = '0000-00-00 00:00:00') limit 1 2018-12-13 14:23:19.855019 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 100 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Rates Information =================== 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] ID : 0 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Code : 3211177971 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Destination : Local 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Connectcost : 0 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Includedseconds : 0 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Cost : 0 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Initial Increment : 60 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Increment : 60 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] Accid : 5 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] ================================================================ 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML:5 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Userinfo XML:5 2018-12-13 14:23:19.855019 [INFO] switch_cpp.cpp:1365 [ASTPP] [userinfo] Actual CustomerInfo XML : 5 2018-12-13 14:23:19.855019 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLINBOUND] Caller ID Translation Starts 2018-12-13 14:23:19.855019 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLINBOUND] Caller ID Translation Ends 2018-12-13 14:23:19.855019 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Generated XML:
2018-12-13 14:23:19.855019 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fbdcc0617e0 released. Dialplan: sofia/default/32490112449@109.68.167.132 parsing [default->3211177971] continue=false Dialplan: sofia/default/32490112449@109.68.167.132 Regex (PASS) [3211177971] destination_number(3211177971) =~ /3211177971/ break=on-false Dialplan: sofia/default/32490112449@109.68.167.132 Action set(effective_destination_number=3211177971) Dialplan: sofia/default/32490112449@109.68.167.132 Action sched_hangup(+6000 normal_clearing) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(callstart=2018-12-13 13:24:22) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(hangup_after_bridge=true) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(continue_on_fail=!USER_BUSY) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(account_id=5) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(parent_id=0) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(entity_id=0) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(call_processed=internal) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(call_direction=inbound) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(accountname=EDGE) Dialplan: sofia/default/32490112449@109.68.167.132 Action export(t38_passthru=true) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(fax_enable_t38=true) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(fax_enable_t38_request=true) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(origination_rates_did=ID:2|CODE:^.3211177971.*|DESTINATION:3211177971|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|ACCID:5) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(origination_rates=ID:0|CODE:3211177971|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:60|RATEGROUP:1|MARKUP:0|ACCID:5) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(original_caller_id_name=32490112449) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(original_caller_id_number=32490112449) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(effective_caller_id_name=32490112449) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(effective_caller_id_number=32490112449) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(receiver_accid=5) Dialplan: sofia/default/32490112449@109.68.167.132 Action set(calltype=DIRECT-IP) Dialplan: sofia/default/32490112449@109.68.167.132 Action bridge([leg_timeout=0]sofia/${sofia_profile_name}/3211177971@109.68.167.132) 2018-12-13 14:23:19.855019 [DEBUG] switch_core_state_machine.c:286 (sofia/default/32490112449@109.68.167.132) State Change CS_ROUTING -> CS_EXECUTE 2018-12-13 14:23:19.855019 [DEBUG] switch_core_state_machine.c:643 (sofia/default/32490112449@109.68.167.132) State ROUTING going to sleep 2018-12-13 14:23:19.855019 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_EXECUTE (Cur 31 Tot 3919) 2018-12-13 14:23:19.855019 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE 2018-12-13 14:23:19.855019 [DEBUG] mod_sofia.c:198 sofia/default/32490112449@109.68.167.132 SOFIA EXECUTE 2018-12-13 14:23:19.855019 [DEBUG] switch_core_state_machine.c:328 sofia/default/32490112449@109.68.167.132 Standard EXECUTE EXECUTE sofia/default/32490112449@109.68.167.132 set(effective_destination_number=3211177971) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [effective_destination_number]=[3211177971] EXECUTE sofia/default/32490112449@109.68.167.132 sched_hangup(+6000 normal_clearing) 2018-12-13 14:23:19.855019 [DEBUG] switch_scheduler.c:249 Added task 2989 switch_ivr_schedule_hangup (1155c53d-b450-4c82-ac7a-8f5a0b2ee02d) to run at 1544713399 EXECUTE sofia/default/32490112449@109.68.167.132 set(callstart=2018-12-13 13:24:22) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [callstart]=[2018-12-13 13:24:22] EXECUTE sofia/default/32490112449@109.68.167.132 set(hangup_after_bridge=true) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [hangup_after_bridge]=[true] EXECUTE sofia/default/32490112449@109.68.167.132 set(continue_on_fail=!USER_BUSY) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [continue_on_fail]=[!USER_BUSY] EXECUTE sofia/default/32490112449@109.68.167.132 set(account_id=5) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [account_id]=[5] EXECUTE sofia/default/32490112449@109.68.167.132 set(parent_id=0) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [parent_id]=[0] EXECUTE sofia/default/32490112449@109.68.167.132 set(entity_id=0) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [entity_id]=[0] EXECUTE sofia/default/32490112449@109.68.167.132 set(call_processed=internal) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [call_processed]=[internal] EXECUTE sofia/default/32490112449@109.68.167.132 set(call_direction=inbound) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [call_direction]=[inbound] EXECUTE sofia/default/32490112449@109.68.167.132 set(accountname=EDGE) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [accountname]=[EDGE] EXECUTE sofia/default/32490112449@109.68.167.132 export(t38_passthru=true) 2018-12-13 14:23:19.855019 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [t38_passthru]=[true] EXECUTE sofia/default/32490112449@109.68.167.132 set(fax_enable_t38=true) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [fax_enable_t38]=[true] EXECUTE sofia/default/32490112449@109.68.167.132 set(fax_enable_t38_request=true) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [fax_enable_t38_request]=[true] EXECUTE sofia/default/32490112449@109.68.167.132 set(origination_rates_did=ID:2|CODE:^.3211177971.*|DESTINATION:3211177971|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|ACCID:5) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [origination_rates_did]=[ID:2|CODE:^.3211177971.*|DESTINATION:3211177971|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:0.00000|INC:0|INITIALBLOCK:0|RATEGROUP:0|MARKUP:0|ACCID:5] EXECUTE sofia/default/32490112449@109.68.167.132 set(origination_rates=ID:0|CODE:3211177971|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:60|RATEGROUP:1|MARKUP:0|ACCID:5) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [origination_rates]=[ID:0|CODE:3211177971|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:60|RATEGROUP:1|MARKUP:0|ACCID:5] EXECUTE sofia/default/32490112449@109.68.167.132 set(original_caller_id_name=32490112449) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [original_caller_id_name]=[32490112449] EXECUTE sofia/default/32490112449@109.68.167.132 set(original_caller_id_number=32490112449) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [original_caller_id_number]=[32490112449] EXECUTE sofia/default/32490112449@109.68.167.132 set(effective_caller_id_name=32490112449) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [effective_caller_id_name]=[32490112449] EXECUTE sofia/default/32490112449@109.68.167.132 set(effective_caller_id_number=32490112449) 2018-12-13 14:23:19.855019 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [effective_caller_id_number]=[32490112449] EXECUTE sofia/default/32490112449@109.68.167.132 set(receiver_accid=5) 2018-12-13 14:23:19.874999 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [receiver_accid]=[5] EXECUTE sofia/default/32490112449@109.68.167.132 set(calltype=DIRECT-IP) 2018-12-13 14:23:19.874999 [DEBUG] mod_dptools.c:1548 SET sofia/default/32490112449@109.68.167.132 [calltype]=[DIRECT-IP] EXECUTE sofia/default/32490112449@109.68.167.132 bridge([leg_timeout=0]sofia/default/3211177971@109.68.167.132) 2018-12-13 14:23:19.874999 [DEBUG] switch_channel.c:1250 sofia/default/32490112449@109.68.167.132 EXPORTING[export_vars] [t38_passthru]=[true] to event 2018-12-13 14:23:19.874999 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-12-13 14:23:19.874999 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables 2018-12-13 14:23:19.874999 [NOTICE] switch_channel.c:1104 New Channel sofia/default/3211177971@109.68.167.132 [b42492ee-1f98-45c8-b175-62e81acaa50d] 2018-12-13 14:23:19.874999 [DEBUG] mod_sofia.c:4819 (sofia/default/3211177971@109.68.167.132) State Change CS_NEW -> CS_INIT 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_INIT (Cur 32 Tot 3920) 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:627 (sofia/default/3211177971@109.68.167.132) State INIT 2018-12-13 14:23:19.874999 [DEBUG] mod_sofia.c:90 sofia/default/3211177971@109.68.167.132 SOFIA INIT 2018-12-13 14:23:19.874999 [DEBUG] sofia_glue.c:1295 sofia/default/3211177971@109.68.167.132 sending invite version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit Local SDP: v=0 o=FreeSWITCH 1544684627 1544684628 IN IP4 109.68.167.132 s=FreeSWITCH c=IN IP4 109.68.167.132 t=0 0 m=audio 22772 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:40 sofia/default/3211177971@109.68.167.132 Standard INIT 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:48 (sofia/default/3211177971@109.68.167.132) State Change CS_INIT -> CS_ROUTING 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:627 (sofia/default/3211177971@109.68.167.132) State INIT going to sleep 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_ROUTING (Cur 32 Tot 3920) 2018-12-13 14:23:19.874999 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [calling][0] 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:643 (sofia/default/3211177971@109.68.167.132) State ROUTING 2018-12-13 14:23:19.874999 [DEBUG] mod_sofia.c:143 sofia/default/3211177971@109.68.167.132 SOFIA ROUTING 2018-12-13 14:23:19.874999 [DEBUG] switch_ivr_originate.c:67 (sofia/default/3211177971@109.68.167.132) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:643 (sofia/default/3211177971@109.68.167.132) State ROUTING going to sleep 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_CONSUME_MEDIA (Cur 32 Tot 3920) 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:662 (sofia/default/3211177971@109.68.167.132) State CONSUME_MEDIA 2018-12-13 14:23:19.874999 [CRIT] switch_core_session.c:2283 Throttle Error! 32 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:662 (sofia/default/3211177971@109.68.167.132) State CONSUME_MEDIA going to sleep 2018-12-13 14:23:19.874999 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.874999 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 32 Tot 3920) 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.874999 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 32 Tot 3920) 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.874999 [INFO] mod_json_cdr.c:271 Process [b42492ee-1f98-45c8-b175-62e81acaa50d.cdr.json] 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.874999 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.874999 [DEBUG] switch_core_session.c:1665 Session 3920 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.895038 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.895038 [NOTICE] switch_core_session.c:1683 Session 3920 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.895038 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 31 Tot 3920) 2018-12-13 14:23:19.895038 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.895038 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.895038 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.895038 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 31 Tot 3920) 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.895038 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.895038 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 31 Tot 3920) 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.895038 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.895038 [INFO] mod_json_cdr.c:271 Process [1155c53d-b450-4c82-ac7a-8f5a0b2ee02d.cdr.json] 2018-12-13 14:23:19.895038 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.895038 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 31 Tot 3920) 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.895038 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 31 Tot 3920) 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.895038 [INFO] mod_json_cdr.c:271 Process [55bc941f-8659-477f-830f-691ebe1ce3cb.cdr.json] 2018-12-13 14:23:19.895038 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.895038 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.895038 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 31 Tot 3920) 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.895038 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.895038 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 31 Tot 3920) 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.895038 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.895038 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.895038 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 31 Tot 3920) 2018-12-13 14:23:19.895038 [INFO] mod_json_cdr.c:271 Process [5bc349c5-27bc-4241-9f49-c98e148a8712.cdr.json] 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.895038 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 31 Tot 3920) 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.895038 [DEBUG] switch_core_session.c:1665 Session 3918 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.895038 [NOTICE] switch_core_session.c:1683 Session 3918 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.895038 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.895038 [INFO] mod_json_cdr.c:271 Process [0225eb46-a7e5-404e-83c0-98f0f6270f19.cdr.json] 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 30 Tot 3920) 2018-12-13 14:23:19.895038 [DEBUG] switch_core_session.c:1665 Session 3919 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.895038 [NOTICE] switch_core_session.c:1683 Session 3919 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.895038 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 29 Tot 3920) 2018-12-13 14:23:19.895038 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.895038 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.895038 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.915002 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 29 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_session.c:1665 Session 3916 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.915002 [NOTICE] switch_core_session.c:1683 Session 3916 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.915002 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 28 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 28 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.915002 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.915002 [INFO] mod_json_cdr.c:271 Process [86cc5a68-8bf0-413b-9e8b-96a6ae902602.cdr.json] 2018-12-13 14:23:19.915002 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.915002 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 28 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 28 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_session.c:1665 Session 3917 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.915002 [NOTICE] switch_core_session.c:1683 Session 3917 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.915002 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.915002 [INFO] mod_json_cdr.c:271 Process [ab28dab2-955f-4ed4-adcb-d2155b300009.cdr.json] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 27 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.915002 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 27 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 27 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.915002 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.915002 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.915002 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.915002 [INFO] mod_json_cdr.c:271 Process [4fab2a40-1fcd-49a4-8be5-40f46c1d6b80.cdr.json] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_session.c:1665 Session 3914 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 27 Tot 3920) 2018-12-13 14:23:19.915002 [NOTICE] switch_core_session.c:1683 Session 3914 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.915002 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 26 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 26 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.915002 [INFO] mod_json_cdr.c:271 Process [4849400c-fce4-4ad2-916b-6c8068a5fe7b.cdr.json] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_session.c:1665 Session 3915 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.915002 [NOTICE] switch_core_session.c:1683 Session 3915 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.915002 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 25 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.915002 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 25 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 25 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.915002 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.915002 [INFO] mod_json_cdr.c:271 Process [b9cce595-3fee-47d3-914e-30117275effa.cdr.json] 2018-12-13 14:23:19.915002 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.915002 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 25 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 25 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.915002 [INFO] mod_json_cdr.c:271 Process [c9be79ec-d207-435d-8521-32faf5d40b92.cdr.json] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_session.c:1665 Session 3912 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.915002 [NOTICE] switch_core_session.c:1683 Session 3912 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.915002 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 24 Tot 3920) 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.915002 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.915002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_session.c:1665 Session 3913 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.935002 [NOTICE] switch_core_session.c:1683 Session 3913 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.935002 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 23 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.935002 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.935002 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 23 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 23 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.935002 [INFO] mod_json_cdr.c:271 Process [2db21c1c-caa0-4014-bcb6-4c31d3c0ddbe.cdr.json] 2018-12-13 14:23:19.935002 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.935002 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 23 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 23 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.935002 [INFO] mod_json_cdr.c:271 Process [6e8328b9-e05e-44b4-9462-c9bb73f27d7b.cdr.json] 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_session.c:1665 Session 3910 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.935002 [NOTICE] switch_core_session.c:1683 Session 3910 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.935002 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 22 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_session.c:1665 Session 3911 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.935002 [NOTICE] switch_core_session.c:1683 Session 3911 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.935002 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 21 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.935002 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.935002 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 21 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 21 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.935002 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.935002 [INFO] mod_json_cdr.c:271 Process [51f7f579-7c9f-4270-9a6c-bba5570f4b36.cdr.json] 2018-12-13 14:23:19.935002 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.935002 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 21 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_session.c:1665 Session 3908 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.935002 [NOTICE] switch_core_session.c:1683 Session 3908 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.935002 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 20 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 20 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.935002 [INFO] mod_json_cdr.c:271 Process [5c6f43bf-4728-435c-9399-a479f98e786b.cdr.json] 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_session.c:1665 Session 3909 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.935002 [NOTICE] switch_core_session.c:1683 Session 3909 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.935002 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 19 Tot 3920) 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.935002 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.935002 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.935002 [DEBUG] switch_core_session.c:1665 Session 3906 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.955004 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1683 Session 3906 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 18 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.955004 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 18 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_session.c:1665 Session 3907 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1683 Session 3907 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 17 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 17 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.955004 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.955004 [INFO] mod_json_cdr.c:271 Process [b979dd9b-6d15-4990-bed7-0a2a2b014aaa.cdr.json] 2018-12-13 14:23:19.955004 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.955004 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 17 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 17 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.955004 [INFO] mod_json_cdr.c:271 Process [4cd2da34-8d15-42cb-90e4-ceeda0651c7a.cdr.json] 2018-12-13 14:23:19.955004 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.955004 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 17 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 17 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.955004 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.955004 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.955004 [INFO] mod_json_cdr.c:271 Process [d6dda435-028b-4643-aa52-11b1b2287126.cdr.json] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 17 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 17 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.955004 [INFO] mod_json_cdr.c:271 Process [2b241875-796d-47ad-9a58-615dfa68f575.cdr.json] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_session.c:1665 Session 3904 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1683 Session 3904 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 16 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_session.c:1665 Session 3905 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1683 Session 3905 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 15 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_session.c:1665 Session 3902 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.955004 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1683 Session 3902 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 14 Tot 3920) 2018-12-13 14:23:19.955004 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.955004 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 14 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 14 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.955004 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_session.c:1665 Session 3903 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1683 Session 3903 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.955004 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.955004 [INFO] mod_json_cdr.c:271 Process [2f1ec0a5-8052-4fd7-bf68-0014321c6a04.cdr.json] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 13 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.955004 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 13 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.955004 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 13 Tot 3920) 2018-12-13 14:23:19.955004 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.955004 [INFO] mod_json_cdr.c:271 Process [e5ab6e84-0385-465c-afd0-96115840621c.cdr.json] 2018-12-13 14:23:19.975014 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.975014 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 13 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 13 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.975014 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.975014 [INFO] mod_json_cdr.c:271 Process [42e42ff0-794c-4846-afb6-87bfaa3b614c.cdr.json] 2018-12-13 14:23:19.975014 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.975014 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 13 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 13 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.975014 [INFO] mod_json_cdr.c:271 Process [292d2299-82ea-442e-ba54-0e35b178f00c.cdr.json] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_session.c:1665 Session 3900 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.975014 [NOTICE] switch_core_session.c:1683 Session 3900 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.975014 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 12 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_session.c:1665 Session 3901 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.975014 [NOTICE] switch_core_session.c:1683 Session 3901 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.975014 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 11 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.975014 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 11 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 11 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.975014 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.975014 [INFO] mod_json_cdr.c:271 Process [508ce523-1591-49cc-a1ac-954493cf6ab8.cdr.json] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_session.c:1665 Session 3898 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.975014 [NOTICE] switch_core_session.c:1683 Session 3898 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.975014 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.975014 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.975014 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 10 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 10 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 10 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.975014 [INFO] mod_json_cdr.c:271 Process [ca544366-c54a-444b-b71f-88018be130d8.cdr.json] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_session.c:1665 Session 3899 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.975014 [NOTICE] switch_core_session.c:1683 Session 3899 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.975014 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 9 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.975014 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 9 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_session.c:1665 Session 3896 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.975014 [NOTICE] switch_core_session.c:1683 Session 3896 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.975014 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 8 Tot 3920) 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.975014 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.975014 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 8 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.995010 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.995010 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.995010 [INFO] mod_json_cdr.c:271 Process [c70dfed2-39ef-4b9e-b9ae-ec8ee9d7fdd9.cdr.json] 2018-12-13 14:23:19.995010 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 8 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 8 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.995010 [INFO] mod_json_cdr.c:271 Process [51ee9169-c3bf-4321-a3e3-80de4c5df675.cdr.json] 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_session.c:1665 Session 3897 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.995010 [NOTICE] switch_core_session.c:1683 Session 3897 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.995010 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 7 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_session.c:1665 Session 3894 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.995010 [NOTICE] switch_core_session.c:1683 Session 3894 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.995010 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.995010 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 6 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 6 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 6 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.995010 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.995010 [INFO] mod_json_cdr.c:271 Process [fbaa46e5-2dfa-47e2-988d-483f9b22fa15.cdr.json] 2018-12-13 14:23:19.995010 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.995010 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 6 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_session.c:1665 Session 3895 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.995010 [NOTICE] switch_core_session.c:1683 Session 3895 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:19.995010 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 5 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 5 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.995010 [INFO] mod_json_cdr.c:271 Process [483a23fe-3b87-4ed4-848f-a663c37ee4ae.cdr.json] 2018-12-13 14:23:19.995010 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.995010 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@109.68.167.132 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.995010 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@109.68.167.132 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@109.68.167.132) State EXECUTE going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_HANGUP (Cur 5 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@109.68.167.132) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@109.68.167.132 Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@109.68.167.132) Running State Change CS_REPORTING (Cur 5 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_session.c:1665 Session 3892 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:19.995010 [NOTICE] switch_core_session.c:1683 Session 3892 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:19.995010 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:19.995010 [DEBUG] sofia.c:6257 Remote Reason: 41 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 4 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:19.995010 [INFO] mod_json_cdr.c:271 Process [5b92f1e5-1a48-41bd-8086-35caac3c5d53.cdr.json] 2018-12-13 14:23:19.995010 [DEBUG] sofia.c:7084 Channel sofia/default/3211177971@109.68.167.132 entering state [terminated][503] 2018-12-13 14:23:19.995010 [NOTICE] sofia.c:8273 Hangup sofia/default/3211177971@109.68.167.132 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_HANGUP (Cur 4 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3211177971@109.68.167.132) Callstate Change DOWN -> HANGUP 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP 2018-12-13 14:23:19.995010 [DEBUG] mod_sofia.c:438 Channel sofia/default/3211177971@109.68.167.132 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:60 sofia/default/3211177971@109.68.167.132 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:852 (sofia/default/3211177971@109.68.167.132) State HANGUP going to sleep 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:619 (sofia/default/3211177971@109.68.167.132) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:584 (sofia/default/3211177971@109.68.167.132) Running State Change CS_REPORTING (Cur 4 Tot 3920) 2018-12-13 14:23:19.995010 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING 2018-12-13 14:23:19.995010 [INFO] mod_json_cdr.c:271 Process [20fe56d8-c839-4ac6-9918-3f10b2a0e77f.cdr.json] 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_session.c:1665 Session 3893 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:20.014999 [NOTICE] switch_core_session.c:1683 Session 3893 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:20.014999 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 3 Tot 3920) 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:20.014999 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:174 sofia/default/3211177971@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:938 (sofia/default/3211177971@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:610 (sofia/default/3211177971@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_session.c:1665 Session 3890 (sofia/default/3211177971@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:20.014999 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:20.014999 [NOTICE] switch_core_session.c:1683 Session 3890 (sofia/default/3211177971@109.68.167.132) Ended 2018-12-13 14:23:20.014999 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/3211177971@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:741 (sofia/default/3211177971@109.68.167.132) Running State Change CS_DESTROY (Cur 2 Tot 3920) 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY 2018-12-13 14:23:20.014999 [DEBUG] mod_sofia.c:343 sofia/default/3211177971@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:181 sofia/default/3211177971@109.68.167.132 Standard DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:751 (sofia/default/3211177971@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:20.014999 [INFO] mod_dptools.c:3436 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:20.014999 [NOTICE] switch_channel.c:4844 Hangup sofia/default/32490112449@sip.voip.united-telecom.be [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2018-12-13 14:23:20.014999 [DEBUG] switch_core_session.c:2815 sofia/default/32490112449@sip.voip.united-telecom.be skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:650 (sofia/default/32490112449@sip.voip.united-telecom.be) State EXECUTE going to sleep 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@sip.voip.united-telecom.be) Running State Change CS_HANGUP (Cur 2 Tot 3920) 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:850 (sofia/default/32490112449@sip.voip.united-telecom.be) Callstate Change RINGING -> HANGUP 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@sip.voip.united-telecom.be) State HANGUP 2018-12-13 14:23:20.014999 [DEBUG] mod_sofia.c:432 sofia/default/32490112449@sip.voip.united-telecom.be Overriding SIP cause 503 with 503 from the other leg 2018-12-13 14:23:20.014999 [DEBUG] mod_sofia.c:438 Channel sofia/default/32490112449@sip.voip.united-telecom.be hanging up, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:20.014999 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:60 sofia/default/32490112449@sip.voip.united-telecom.be Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:852 (sofia/default/32490112449@sip.voip.united-telecom.be) State HANGUP going to sleep 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:619 (sofia/default/32490112449@sip.voip.united-telecom.be) State Change CS_HANGUP -> CS_REPORTING 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:584 (sofia/default/32490112449@sip.voip.united-telecom.be) Running State Change CS_REPORTING (Cur 2 Tot 3920) 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@sip.voip.united-telecom.be) State REPORTING 2018-12-13 14:23:20.014999 [INFO] mod_json_cdr.c:271 Process [475f845d-4d9c-4541-888f-1ea0f971bbc0.cdr.json] 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@109.68.167.132 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@109.68.167.132) State REPORTING going to sleep 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@109.68.167.132) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_session.c:1665 Session 3891 (sofia/default/32490112449@109.68.167.132) Locked, Waiting on external entities 2018-12-13 14:23:20.014999 [NOTICE] switch_core_session.c:1683 Session 3891 (sofia/default/32490112449@109.68.167.132) Ended 2018-12-13 14:23:20.014999 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@109.68.167.132 [CS_DESTROY] 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@109.68.167.132) Running State Change CS_DESTROY (Cur 1 Tot 3920) 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY 2018-12-13 14:23:20.014999 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@109.68.167.132 SOFIA DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@109.68.167.132 Standard DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@109.68.167.132) State DESTROY going to sleep 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:174 sofia/default/32490112449@sip.voip.united-telecom.be Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:938 (sofia/default/32490112449@sip.voip.united-telecom.be) State REPORTING going to sleep 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:610 (sofia/default/32490112449@sip.voip.united-telecom.be) State Change CS_REPORTING -> CS_DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_session.c:1665 Session 3889 (sofia/default/32490112449@sip.voip.united-telecom.be) Locked, Waiting on external entities 2018-12-13 14:23:20.014999 [NOTICE] switch_core_session.c:1683 Session 3889 (sofia/default/32490112449@sip.voip.united-telecom.be) Ended 2018-12-13 14:23:20.014999 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/32490112449@sip.voip.united-telecom.be [CS_DESTROY] 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:741 (sofia/default/32490112449@sip.voip.united-telecom.be) Running State Change CS_DESTROY (Cur 0 Tot 3920) 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@sip.voip.united-telecom.be) State DESTROY 2018-12-13 14:23:20.014999 [DEBUG] mod_sofia.c:343 sofia/default/32490112449@sip.voip.united-telecom.be SOFIA DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:181 sofia/default/32490112449@sip.voip.united-telecom.be Standard DESTROY 2018-12-13 14:23:20.014999 [DEBUG] switch_core_state_machine.c:751 (sofia/default/32490112449@sip.voip.united-telecom.be) State DESTROY going to sleep 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2974 switch_ivr_schedule_hangup (475f845d-4d9c-4541-888f-1ea0f971bbc0) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2975 switch_ivr_schedule_hangup (5b92f1e5-1a48-41bd-8086-35caac3c5d53) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2976 switch_ivr_schedule_hangup (fbaa46e5-2dfa-47e2-988d-483f9b22fa15) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2977 switch_ivr_schedule_hangup (c70dfed2-39ef-4b9e-b9ae-ec8ee9d7fdd9) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2978 switch_ivr_schedule_hangup (508ce523-1591-49cc-a1ac-954493cf6ab8) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2979 switch_ivr_schedule_hangup (42e42ff0-794c-4846-afb6-87bfaa3b614c) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2980 switch_ivr_schedule_hangup (2f1ec0a5-8052-4fd7-bf68-0014321c6a04) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2981 switch_ivr_schedule_hangup (d6dda435-028b-4643-aa52-11b1b2287126) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2982 switch_ivr_schedule_hangup (b979dd9b-6d15-4990-bed7-0a2a2b014aaa) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2983 switch_ivr_schedule_hangup (51f7f579-7c9f-4270-9a6c-bba5570f4b36) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2984 switch_ivr_schedule_hangup (2db21c1c-caa0-4014-bcb6-4c31d3c0ddbe) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2985 switch_ivr_schedule_hangup (b9cce595-3fee-47d3-914e-30117275effa) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2986 switch_ivr_schedule_hangup (4fab2a40-1fcd-49a4-8be5-40f46c1d6b80) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2987 switch_ivr_schedule_hangup (86cc5a68-8bf0-413b-9e8b-96a6ae902602) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2988 switch_ivr_schedule_hangup (5bc349c5-27bc-4241-9f49-c98e148a8712) 2018-12-13 14:23:20.355007 [DEBUG] switch_scheduler.c:144 Deleting task 2989 switch_ivr_schedule_hangup (1155c53d-b450-4c82-ac7a-8f5a0b2ee02d) 2018-12-13 14:23:20.435028 [CRIT] switch_time.c:1235 Over Session Rate of 30!