Hi all,
I am facing an issue with outbound call it get drop immediately from the dialer side showing 603 State. Can you please help me how to resolve this issue?
I am attaching log for your review below:
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/945353@64.187.222.69:5060) State Change CS_ROUTING -> CS_EXECUTE
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/945353@64.187.222.69:5060) State ROUTING going to sleep
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/945353@64.187.222.69:5060) Running State Change CS_EXECUTE (Cur 1 Tot 39)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/945353@64.187.222.69:5060) State EXECUTE
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_sofia.c:198 sofia/internal/945353@64.187.222.69:5060 SOFIA EXECUTE
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:328 sofia/internal/945353@64.187.222.69:5060 Standard EXECUTE
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 export(call_direction=local)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[local]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 export(origination_callee_id_name=01670806867)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[01670806867]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(RFC2822_DATE=Mon, 23 Apr 2018 09:47:08 -0400)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [RFC2822_DATE]=[Mon, 23 Apr 2018 09:47:08 -0400]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 hash(insert/103.110.161.11-last_dial/1003/01670806867)
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(sip_h_X-accountcode=)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [sip_h_X-accountcode]=[UNDEF]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 export(call_direction=outbound)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[outbound]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 unset(call_timeout)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1693 UNSET [call_timeout]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(hangup_after_bridge=true)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [hangup_after_bridge]=[true]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(effective_caller_id_name=)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [effective_caller_id_name]=[UNDEF]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(effective_caller_id_number=)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [effective_caller_id_number]=[UNDEF]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(inherit_codec=true)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [inherit_codec]=[true]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(ignore_display_updates=true)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [ignore_display_updates]=[true]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(callee_id_number=01670806867)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [callee_id_number]=[01670806867]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(continue_on_fail=true)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [continue_on_fail]=[true]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 bridge(sofia/gateway/69bf0a1d-8bf1-4983-984a-0e88a9ed3e17/01670806867)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1250 sofia/internal/945353@64.187.222.69:5060 EXPORTING[export_vars] [domain_name]=[103.110.161.11] to event
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1250 sofia/internal/945353@64.187.222.69:5060 EXPORTING[export_vars] [call_direction]=[outbound] to event
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1250 sofia/internal/945353@64.187.222.69:5060 EXPORTING[export_vars] [origination_callee_id_name]=[01670806867] to event
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1250 sofia/internal/945353@64.187.222.69:5060 EXPORTING[export_vars] [call_direction]=[outbound] to event
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [NOTICE] switch_channel.c:1104 New Channel sofia/external/01670806867 [7036bce7-5033-4303-b766-568716cea479]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] mod_sofia.c:4819 (sofia/external/01670806867) State Change CS_NEW -> CS_INIT
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_INIT (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:627 (sofia/external/01670806867) State INIT
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] mod_sofia.c:90 sofia/external/01670806867 SOFIA INIT
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] sofia_glue.c:1295 sofia/external/01670806867 sending invite version: 1.6.20 -37-987c9b9 64bit
7036bce7-5033-4303-b766-568716cea479 Local SDP:
7036bce7-5033-4303-b766-568716cea479 v=0
7036bce7-5033-4303-b766-568716cea479 o=FreeSWITCH 1524459866 1524459867 IN IP4 103.110.161.11
7036bce7-5033-4303-b766-568716cea479 s=FreeSWITCH
7036bce7-5033-4303-b766-568716cea479 c=IN IP4 103.110.161.11
7036bce7-5033-4303-b766-568716cea479 t=0 0
7036bce7-5033-4303-b766-568716cea479 m=audio 31362 RTP/AVP 18 0 8 101 13
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:18 G729/8000
7036bce7-5033-4303-b766-568716cea479 a=fmtp:18 annexb=no
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:0 PCMU/8000
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:8 PCMA/8000
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:101 telephone-event/8000
7036bce7-5033-4303-b766-568716cea479 a=fmtp:101 0-16
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:13 CN/8000
7036bce7-5033-4303-b766-568716cea479 a=ptime:20
7036bce7-5033-4303-b766-568716cea479 a=sendrecv
7036bce7-5033-4303-b766-568716cea479
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:40 sofia/external/01670806867 Standard INIT
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:48 (sofia/external/01670806867) State Change CS_INIT -> CS_ROUTING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:627 (sofia/external/01670806867) State INIT going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_ROUTING (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] sofia.c:7084 Channel sofia/external/01670806867 entering state [calling][0]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:643 (sofia/external/01670806867) State ROUTING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] mod_sofia.c:143 sofia/external/01670806867 SOFIA ROUTING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_ivr_originate.c:67 (sofia/external/01670806867) State Change CS_ROUTING -> CS_CONSUME_MEDIA
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:643 (sofia/external/01670806867) State ROUTING going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:662 (sofia/external/01670806867) State CONSUME_MEDIA
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:662 (sofia/external/01670806867) State CONSUME_MEDIA going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.474636 [DEBUG] sofia.c:7084 Channel sofia/external/01670806867 entering state [calling][0]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] sofia.c:7084 Channel sofia/external/01670806867 entering state [proceeding][183]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] sofia.c:7094 Remote SDP:
7036bce7-5033-4303-b766-568716cea479 v=0
7036bce7-5033-4303-b766-568716cea479 o=Sippy 134875256 1 IN IP4 182.16.159.6
7036bce7-5033-4303-b766-568716cea479 s=Asterisk PBX 11.9.0
7036bce7-5033-4303-b766-568716cea479 t=0 0
7036bce7-5033-4303-b766-568716cea479 m=audio 36014 RTP/AVP 0 8 101
7036bce7-5033-4303-b766-568716cea479 c=IN IP4 182.16.159.6
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:0 PCMU/8000
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:8 PCMA/8000
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:101 telephone-event/8000
7036bce7-5033-4303-b766-568716cea479 a=fmtp:101 0-16
7036bce7-5033-4303-b766-568716cea479
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external/01670806867 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_codec.c:111 sofia/external/01670806867 Original read codec set to PCMU:0
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4767 sofia/external/01670806867 Set 2833 dtmf send payload to 101 recv payload to 101
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/external/01670806867] 192.168.0.109 port 31362 -> 182.16.159.6 port 36014 codec: 0 ms: 20
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:7180 sofia/external/01670806867 Set 2833 dtmf send payload to 101
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:7187 sofia/external/01670806867 Set 2833 dtmf receive payload to 101
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:7210 sofia/external/01670806867 Set rtp dtmf delay to 40
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/01670806867!
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_channel.c:3474 (sofia/external/01670806867) Callstate Change DOWN -> EARLY
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.576049 [DEBUG] switch_ivr_originate.c:413 Codec string PCMU@8000h@20i not supported on sofia/internal/945353@64.187.222.69:5060, skipping inheritance
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.576049 [INFO] switch_ivr_originate.c:3654 Sending early media
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/945353@64.187.222.69:5060] 192.168.0.109 port 30926 -> 64.187.222.69 port 27050 codec: 18 ms: 20
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.576049 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] switch_core_media.c:7180 sofia/internal/945353@64.187.222.69:5060 Set 2833 dtmf send payload to 101
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] switch_core_media.c:7187 sofia/internal/945353@64.187.222.69:5060 Set 2833 dtmf receive payload to 101
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] switch_core_media.c:7210 sofia/internal/945353@64.187.222.69:5060 Set rtp dtmf delay to 40
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] mod_sofia.c:2364 Ring SDP:
747a0031-b838-4c84-9b75-0c972cae691b v=0
747a0031-b838-4c84-9b75-0c972cae691b o=FreeSWITCH 1524460302 1524460303 IN IP4 103.110.161.11
747a0031-b838-4c84-9b75-0c972cae691b s=FreeSWITCH
747a0031-b838-4c84-9b75-0c972cae691b c=IN IP4 103.110.161.11
747a0031-b838-4c84-9b75-0c972cae691b t=0 0
747a0031-b838-4c84-9b75-0c972cae691b m=audio 30926 RTP/AVP 18 101
747a0031-b838-4c84-9b75-0c972cae691b a=rtpmap:18 G729/8000
747a0031-b838-4c84-9b75-0c972cae691b a=fmtp:18 annexb=no
747a0031-b838-4c84-9b75-0c972cae691b a=rtpmap:101 telephone-event/8000
747a0031-b838-4c84-9b75-0c972cae691b a=fmtp:101 0-16
747a0031-b838-4c84-9b75-0c972cae691b a=ptime:20
747a0031-b838-4c84-9b75-0c972cae691b a=sendrecv
747a0031-b838-4c84-9b75-0c972cae691b
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [NOTICE] mod_sofia.c:2367 Pre-Answer sofia/internal/945353@64.187.222.69:5060!
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] switch_channel.c:3474 (sofia/internal/945353@64.187.222.69:5060) Callstate Change RINGING -> EARLY
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] sofia.c:7084 Channel sofia/internal/945353@64.187.222.69:5060 entering state [early][183]
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/external/01670806867]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.595310 [DEBUG] switch_ivr_bridge.c:1614 (sofia/external/01670806867) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.595310 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.595310 [DEBUG] switch_core_state_machine.c:653 (sofia/external/01670806867) State EXCHANGE_MEDIA
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.595310 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:09.274574 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:09.554430 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:16.714444 [DEBUG] sofia.c:7084 Channel sofia/external/01670806867 entering state [proceeding][180]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:16.714444 [NOTICE] sofia.c:7192 Ring-Ready sofia/external/01670806867!
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:16.714444 [DEBUG] switch_channel.c:3346 (sofia/external/01670806867) Callstate Change EARLY -> RINGING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] sofia.c:7084 Channel sofia/external/01670806867 entering state [terminated][603]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [NOTICE] sofia.c:8273 Hangup sofia/external/01670806867 [CS_EXCHANGE_MEDIA] [CALL_REJECTED]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_ivr_bridge.c:712 sofia/external/01670806867 ending bridge by request from read function
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/external/01670806867]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:653 (sofia/external/01670806867) State EXCHANGE_MEDIA going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_HANGUP (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:850 (sofia/external/01670806867) Callstate Change RINGING -> HANGUP
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:852 (sofia/external/01670806867) State HANGUP
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] mod_sofia.c:438 Channel sofia/external/01670806867 hanging up, cause: CALL_REJECTED
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:60 sofia/external/01670806867 Standard HANGUP, cause: CALL_REJECTED
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:852 (sofia/external/01670806867) State HANGUP going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:619 (sofia/external/01670806867) State Change CS_HANGUP -> CS_REPORTING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_REPORTING (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:938 (sofia/external/01670806867) State REPORTING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:174 sofia/external/01670806867 Standard REPORTING, cause: CALL_REJECTED
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:938 (sofia/external/01670806867) State REPORTING going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:610 (sofia/external/01670806867) State Change CS_REPORTING -> CS_DESTROY
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_session.c:1665 Session 40 (sofia/external/01670806867) Locked, Waiting on external entities
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.714806 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/945353@64.187.222.69:5060]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 eval(not_secure)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [NOTICE] switch_core_state_machine.c:385 sofia/internal/945353@64.187.222.69:5060 has executed the last dialplan instruction, hanging up.
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/internal/945353@64.187.222.69:5060 [CS_EXECUTE] [NORMAL_CLEARING]
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/945353@64.187.222.69:5060) State EXECUTE going to sleep
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/945353@64.187.222.69:5060) Running State Change CS_HANGUP (Cur 2 Tot 40)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/945353@64.187.222.69:5060) Callstate Change EARLY -> HANGUP
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/945353@64.187.222.69:5060) State HANGUP
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] mod_sofia.c:432 sofia/internal/945353@64.187.222.69:5060 Overriding SIP cause 480 with 603 from the other leg
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] mod_sofia.c:438 Channel sofia/internal/945353@64.187.222.69:5060 hanging up, cause: NORMAL_CLEARING
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 603
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:60 sofia/internal/945353@64.187.222.69:5060 Standard HANGUP, cause: NORMAL_CLEARING
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/945353@64.187.222.69:5060) State HANGUP going to sleep
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/945353@64.187.222.69:5060) State Change CS_HANGUP -> CS_REPORTING
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/945353@64.187.222.69:5060) Running State Change CS_REPORTING (Cur 2 Tot 40)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/945353@64.187.222.69:5060) State REPORTING
I am facing an issue with outbound call it get drop immediately from the dialer side showing 603 State. Can you please help me how to resolve this issue?
I am attaching log for your review below:
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/945353@64.187.222.69:5060) State Change CS_ROUTING -> CS_EXECUTE
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/945353@64.187.222.69:5060) State ROUTING going to sleep
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/945353@64.187.222.69:5060) Running State Change CS_EXECUTE (Cur 1 Tot 39)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/945353@64.187.222.69:5060) State EXECUTE
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_sofia.c:198 sofia/internal/945353@64.187.222.69:5060 SOFIA EXECUTE
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:328 sofia/internal/945353@64.187.222.69:5060 Standard EXECUTE
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 export(call_direction=local)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[local]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 export(origination_callee_id_name=01670806867)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[01670806867]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(RFC2822_DATE=Mon, 23 Apr 2018 09:47:08 -0400)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [RFC2822_DATE]=[Mon, 23 Apr 2018 09:47:08 -0400]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 hash(insert/103.110.161.11-last_dial/1003/01670806867)
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(sip_h_X-accountcode=)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [sip_h_X-accountcode]=[UNDEF]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 export(call_direction=outbound)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[outbound]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 unset(call_timeout)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1693 UNSET [call_timeout]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(hangup_after_bridge=true)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [hangup_after_bridge]=[true]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(effective_caller_id_name=)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [effective_caller_id_name]=[UNDEF]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(effective_caller_id_number=)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [effective_caller_id_number]=[UNDEF]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(inherit_codec=true)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [inherit_codec]=[true]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(ignore_display_updates=true)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [ignore_display_updates]=[true]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(callee_id_number=01670806867)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [callee_id_number]=[01670806867]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 set(continue_on_fail=true)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] mod_dptools.c:1548 SET sofia/internal/945353@64.187.222.69:5060 [continue_on_fail]=[true]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 bridge(sofia/gateway/69bf0a1d-8bf1-4983-984a-0e88a9ed3e17/01670806867)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1250 sofia/internal/945353@64.187.222.69:5060 EXPORTING[export_vars] [domain_name]=[103.110.161.11] to event
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1250 sofia/internal/945353@64.187.222.69:5060 EXPORTING[export_vars] [call_direction]=[outbound] to event
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1250 sofia/internal/945353@64.187.222.69:5060 EXPORTING[export_vars] [origination_callee_id_name]=[01670806867] to event
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_channel.c:1250 sofia/internal/945353@64.187.222.69:5060 EXPORTING[export_vars] [call_direction]=[outbound] to event
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.435356 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [NOTICE] switch_channel.c:1104 New Channel sofia/external/01670806867 [7036bce7-5033-4303-b766-568716cea479]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] mod_sofia.c:4819 (sofia/external/01670806867) State Change CS_NEW -> CS_INIT
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_INIT (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:627 (sofia/external/01670806867) State INIT
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] mod_sofia.c:90 sofia/external/01670806867 SOFIA INIT
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] sofia_glue.c:1295 sofia/external/01670806867 sending invite version: 1.6.20 -37-987c9b9 64bit
7036bce7-5033-4303-b766-568716cea479 Local SDP:
7036bce7-5033-4303-b766-568716cea479 v=0
7036bce7-5033-4303-b766-568716cea479 o=FreeSWITCH 1524459866 1524459867 IN IP4 103.110.161.11
7036bce7-5033-4303-b766-568716cea479 s=FreeSWITCH
7036bce7-5033-4303-b766-568716cea479 c=IN IP4 103.110.161.11
7036bce7-5033-4303-b766-568716cea479 t=0 0
7036bce7-5033-4303-b766-568716cea479 m=audio 31362 RTP/AVP 18 0 8 101 13
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:18 G729/8000
7036bce7-5033-4303-b766-568716cea479 a=fmtp:18 annexb=no
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:0 PCMU/8000
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:8 PCMA/8000
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:101 telephone-event/8000
7036bce7-5033-4303-b766-568716cea479 a=fmtp:101 0-16
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:13 CN/8000
7036bce7-5033-4303-b766-568716cea479 a=ptime:20
7036bce7-5033-4303-b766-568716cea479 a=sendrecv
7036bce7-5033-4303-b766-568716cea479
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:40 sofia/external/01670806867 Standard INIT
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:48 (sofia/external/01670806867) State Change CS_INIT -> CS_ROUTING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:627 (sofia/external/01670806867) State INIT going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_ROUTING (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] sofia.c:7084 Channel sofia/external/01670806867 entering state [calling][0]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:643 (sofia/external/01670806867) State ROUTING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] mod_sofia.c:143 sofia/external/01670806867 SOFIA ROUTING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_ivr_originate.c:67 (sofia/external/01670806867) State Change CS_ROUTING -> CS_CONSUME_MEDIA
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:643 (sofia/external/01670806867) State ROUTING going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:662 (sofia/external/01670806867) State CONSUME_MEDIA
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.435356 [DEBUG] switch_core_state_machine.c:662 (sofia/external/01670806867) State CONSUME_MEDIA going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.474636 [DEBUG] sofia.c:7084 Channel sofia/external/01670806867 entering state [calling][0]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] sofia.c:7084 Channel sofia/external/01670806867 entering state [proceeding][183]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] sofia.c:7094 Remote SDP:
7036bce7-5033-4303-b766-568716cea479 v=0
7036bce7-5033-4303-b766-568716cea479 o=Sippy 134875256 1 IN IP4 182.16.159.6
7036bce7-5033-4303-b766-568716cea479 s=Asterisk PBX 11.9.0
7036bce7-5033-4303-b766-568716cea479 t=0 0
7036bce7-5033-4303-b766-568716cea479 m=audio 36014 RTP/AVP 0 8 101
7036bce7-5033-4303-b766-568716cea479 c=IN IP4 182.16.159.6
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:0 PCMU/8000
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:8 PCMA/8000
7036bce7-5033-4303-b766-568716cea479 a=rtpmap:101 telephone-event/8000
7036bce7-5033-4303-b766-568716cea479 a=fmtp:101 0-16
7036bce7-5033-4303-b766-568716cea479
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external/01670806867 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_codec.c:111 sofia/external/01670806867 Original read codec set to PCMU:0
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:4767 sofia/external/01670806867 Set 2833 dtmf send payload to 101 recv payload to 101
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/external/01670806867] 192.168.0.109 port 31362 -> 182.16.159.6 port 36014 codec: 0 ms: 20
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:7180 sofia/external/01670806867 Set 2833 dtmf send payload to 101
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:7187 sofia/external/01670806867 Set 2833 dtmf receive payload to 101
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:7210 sofia/external/01670806867 Set rtp dtmf delay to 40
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/01670806867!
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.576049 [DEBUG] switch_channel.c:3474 (sofia/external/01670806867) Callstate Change DOWN -> EARLY
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.576049 [DEBUG] switch_ivr_originate.c:413 Codec string PCMU@8000h@20i not supported on sofia/internal/945353@64.187.222.69:5060, skipping inheritance
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.576049 [INFO] switch_ivr_originate.c:3654 Sending early media
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.576049 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/945353@64.187.222.69:5060] 192.168.0.109 port 30926 -> 64.187.222.69 port 27050 codec: 18 ms: 20
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.576049 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] switch_core_media.c:7180 sofia/internal/945353@64.187.222.69:5060 Set 2833 dtmf send payload to 101
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] switch_core_media.c:7187 sofia/internal/945353@64.187.222.69:5060 Set 2833 dtmf receive payload to 101
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] switch_core_media.c:7210 sofia/internal/945353@64.187.222.69:5060 Set rtp dtmf delay to 40
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] mod_sofia.c:2364 Ring SDP:
747a0031-b838-4c84-9b75-0c972cae691b v=0
747a0031-b838-4c84-9b75-0c972cae691b o=FreeSWITCH 1524460302 1524460303 IN IP4 103.110.161.11
747a0031-b838-4c84-9b75-0c972cae691b s=FreeSWITCH
747a0031-b838-4c84-9b75-0c972cae691b c=IN IP4 103.110.161.11
747a0031-b838-4c84-9b75-0c972cae691b t=0 0
747a0031-b838-4c84-9b75-0c972cae691b m=audio 30926 RTP/AVP 18 101
747a0031-b838-4c84-9b75-0c972cae691b a=rtpmap:18 G729/8000
747a0031-b838-4c84-9b75-0c972cae691b a=fmtp:18 annexb=no
747a0031-b838-4c84-9b75-0c972cae691b a=rtpmap:101 telephone-event/8000
747a0031-b838-4c84-9b75-0c972cae691b a=fmtp:101 0-16
747a0031-b838-4c84-9b75-0c972cae691b a=ptime:20
747a0031-b838-4c84-9b75-0c972cae691b a=sendrecv
747a0031-b838-4c84-9b75-0c972cae691b
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [NOTICE] mod_sofia.c:2367 Pre-Answer sofia/internal/945353@64.187.222.69:5060!
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] switch_channel.c:3474 (sofia/internal/945353@64.187.222.69:5060) Callstate Change RINGING -> EARLY
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] sofia.c:7084 Channel sofia/internal/945353@64.187.222.69:5060 entering state [early][183]
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:08.595310 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/external/01670806867]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.595310 [DEBUG] switch_ivr_bridge.c:1614 (sofia/external/01670806867) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.595310 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.595310 [DEBUG] switch_core_state_machine.c:653 (sofia/external/01670806867) State EXCHANGE_MEDIA
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:08.595310 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:09.274574 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:09.554430 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:16.714444 [DEBUG] sofia.c:7084 Channel sofia/external/01670806867 entering state [proceeding][180]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:16.714444 [NOTICE] sofia.c:7192 Ring-Ready sofia/external/01670806867!
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:16.714444 [DEBUG] switch_channel.c:3346 (sofia/external/01670806867) Callstate Change EARLY -> RINGING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] sofia.c:7084 Channel sofia/external/01670806867 entering state [terminated][603]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [NOTICE] sofia.c:8273 Hangup sofia/external/01670806867 [CS_EXCHANGE_MEDIA] [CALL_REJECTED]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_ivr_bridge.c:712 sofia/external/01670806867 ending bridge by request from read function
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/external/01670806867]
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:653 (sofia/external/01670806867) State EXCHANGE_MEDIA going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_HANGUP (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:850 (sofia/external/01670806867) Callstate Change RINGING -> HANGUP
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:852 (sofia/external/01670806867) State HANGUP
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] mod_sofia.c:438 Channel sofia/external/01670806867 hanging up, cause: CALL_REJECTED
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:60 sofia/external/01670806867 Standard HANGUP, cause: CALL_REJECTED
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:852 (sofia/external/01670806867) State HANGUP going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:619 (sofia/external/01670806867) State Change CS_HANGUP -> CS_REPORTING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:584 (sofia/external/01670806867) Running State Change CS_REPORTING (Cur 2 Tot 40)
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:938 (sofia/external/01670806867) State REPORTING
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:174 sofia/external/01670806867 Standard REPORTING, cause: CALL_REJECTED
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:938 (sofia/external/01670806867) State REPORTING going to sleep
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_state_machine.c:610 (sofia/external/01670806867) State Change CS_REPORTING -> CS_DESTROY
7036bce7-5033-4303-b766-568716cea479 2018-04-23 09:47:36.714806 [DEBUG] switch_core_session.c:1665 Session 40 (sofia/external/01670806867) Locked, Waiting on external entities
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.714806 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/945353@64.187.222.69:5060]
747a0031-b838-4c84-9b75-0c972cae691b EXECUTE sofia/internal/945353@64.187.222.69:5060 eval(not_secure)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [NOTICE] switch_core_state_machine.c:385 sofia/internal/945353@64.187.222.69:5060 has executed the last dialplan instruction, hanging up.
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/internal/945353@64.187.222.69:5060 [CS_EXECUTE] [NORMAL_CLEARING]
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/945353@64.187.222.69:5060) State EXECUTE going to sleep
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/945353@64.187.222.69:5060) Running State Change CS_HANGUP (Cur 2 Tot 40)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/945353@64.187.222.69:5060) Callstate Change EARLY -> HANGUP
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/945353@64.187.222.69:5060) State HANGUP
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] mod_sofia.c:432 sofia/internal/945353@64.187.222.69:5060 Overriding SIP cause 480 with 603 from the other leg
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] mod_sofia.c:438 Channel sofia/internal/945353@64.187.222.69:5060 hanging up, cause: NORMAL_CLEARING
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 603
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:60 sofia/internal/945353@64.187.222.69:5060 Standard HANGUP, cause: NORMAL_CLEARING
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/945353@64.187.222.69:5060) State HANGUP going to sleep
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/945353@64.187.222.69:5060) State Change CS_HANGUP -> CS_REPORTING
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/945353@64.187.222.69:5060) Running State Change CS_REPORTING (Cur 2 Tot 40)
747a0031-b838-4c84-9b75-0c972cae691b 2018-04-23 09:47:36.734813 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/945353@64.187.222.69:5060) State REPORTING