FS_MASTER LOG
2017-06-21 13:42:22.301710 [NOTICE] switch_loadable_module.c:1055 Deleting Application 'socket'
2017-06-21 13:42:22.301710 [DEBUG] switch_loadable_module.c:1057 Write lock interface 'socket' to wait for existing references.
2017-06-21 13:42:22.301710 [NOTICE] switch_loadable_module.c:1110 Deleting API Function 'event_sink'
2017-06-21 13:42:22.301710 [DEBUG] switch_loadable_module.c:1112 Write lock interface 'event_sink' to wait for existing references.
2017-06-21 13:42:22.301710 [CONSOLE] switch_loadable_module.c:2014 Stopping: mod_event_socket
2017-06-21 13:42:22.301710 [NOTICE] mod_event_socket.c:2989 Shutting Down
2017-06-21 13:42:22.301710 [NOTICE] switch_loadable_module.c:115 Thread ended for mod_event_socket
2017-06-21 13:42:22.341666 [INFO] mod_enum.c:879 ENUM Reloaded
2017-06-21 13:42:22.341666 [INFO] switch_time.c:1423 Timezone reloaded 1750 definitions
2017-06-21 13:42:22.341666 [NOTICE] switch_event.c:2140 Event Binding deleted for mod_event_socket:ALL
2017-06-21 13:42:22.341666 [CONSOLE] switch_loadable_module.c:2030 mod_event_socket stopping runtime thread.
2017-06-21 13:42:22.341666 [CONSOLE] switch_loadable_module.c:2034 mod_event_socket unloaded.
2017-06-21 13:42:22.341666 [CONSOLE] switch_loadable_module.c:1540 Successfully Loaded [mod_event_socket]
2017-06-21 13:42:22.341666 [NOTICE] switch_loadable_module.c:292 Adding Application 'socket'
2017-06-21 13:42:22.341666 [NOTICE] switch_loadable_module.c:338 Adding API Function 'event_sink'
2017-06-21 13:42:22.381642 [DEBUG] mod_event_socket.c:2961 Socket up listening on :::8021
2017-06-21 13:42:34.481702 [WARNING] mod_event_socket.c:2659 IP ::ffff:127.0.0.1 Rejected by acl "eventsocket"
2017-06-21 13:43:08.801672 [WARNING] mod_event_socket.c:2659 IP ::ffff:172.20.100.153 Rejected by acl "eventsocket"
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [NOTICE] switch_channel.c:1104 New Channel sofia/external/767432661@172.20.100.3 [25e10655-a9b9-4447-bbe0-4c3081149afb]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] switch_core_state_machine.c:584 (sofia/external/767432661@172.20.100.3) Running State Change CS_NEW (Cur 1 Tot 1)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] sofia.c:9837 sofia/external/767432661@172.20.100.3 receiving invite from 172.20.100.158:5060 version: 1.6.18 -35-6e79667 64bit
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] sofia.c:7048 Channel sofia/external/767432661@172.20.100.3 entering state [received][100]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] sofia.c:7058 Remote SDP:
25e10655-a9b9-4447-bbe0-4c3081149afb v=0
25e10655-a9b9-4447-bbe0-4c3081149afb o=CiscoSystemsSIP-GW-UserAgent 3801 8704 IN IP4 172.20.100.3
25e10655-a9b9-4447-bbe0-4c3081149afb s=SIP Call
25e10655-a9b9-4447-bbe0-4c3081149afb c=IN IP4 172.20.100.3
25e10655-a9b9-4447-bbe0-4c3081149afb t=0 0
25e10655-a9b9-4447-bbe0-4c3081149afb m=audio 17184 RTP/AVP 0 8 18 101
25e10655-a9b9-4447-bbe0-4c3081149afb c=IN IP4 172.20.100.3
25e10655-a9b9-4447-bbe0-4c3081149afb a=rtpmap:0 PCMU/8000
25e10655-a9b9-4447-bbe0-4c3081149afb a=rtpmap:8 PCMA/8000
25e10655-a9b9-4447-bbe0-4c3081149afb a=rtpmap:18 G729/8000
25e10655-a9b9-4447-bbe0-4c3081149afb a=fmtp:18 annexb=yes
25e10655-a9b9-4447-bbe0-4c3081149afb a=rtpmap:101 telephone-event/8000
25e10655-a9b9-4447-bbe0-4c3081149afb a=fmtp:101 0-16
25e10655-a9b9-4447-bbe0-4c3081149afb
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] sofia.c:7450 (sofia/external/767432661@172.20.100.3) State Change CS_NEW -> CS_INIT
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] switch_core_state_machine.c:603 (sofia/external/767432661@172.20.100.3) State NEW
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] switch_core_state_machine.c:584 (sofia/external/767432661@172.20.100.3) Running State Change CS_INIT (Cur 1 Tot 1)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] switch_core_state_machine.c:627 (sofia/external/767432661@172.20.100.3) State INIT
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] mod_sofia.c:90 sofia/external/767432661@172.20.100.3 SOFIA INIT
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] switch_core_state_machine.c:40 sofia/external/767432661@172.20.100.3 Standard INIT
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] switch_core_state_machine.c:48 (sofia/external/767432661@172.20.100.3) State Change CS_INIT -> CS_ROUTING
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] switch_core_state_machine.c:627 (sofia/external/767432661@172.20.100.3) State INIT going to sleep
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] switch_core_state_machine.c:584 (sofia/external/767432661@172.20.100.3) Running State Change CS_ROUTING (Cur 1 Tot 1)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] switch_channel.c:2249 (sofia/external/767432661@172.20.100.3) Callstate Change DOWN -> RINGING
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] switch_core_state_machine.c:643 (sofia/external/767432661@172.20.100.3) State ROUTING
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] mod_sofia.c:143 sofia/external/767432661@172.20.100.3 SOFIA ROUTING
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [DEBUG] switch_core_state_machine.c:236 sofia/external/767432661@172.20.100.3 Standard ROUTING
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.761720 [INFO] mod_dialplan_xml.c:637 Processing 767432661 <767432661>->6891 in context public
25e10655-a9b9-4447-bbe0-4c3081149afb Dialplan: sofia/external/767432661@172.20.100.3 parsing [public->test] continue=false
25e10655-a9b9-4447-bbe0-4c3081149afb Dialplan: sofia/external/767432661@172.20.100.3 Regex (PASS) [test] destination_number(6891) =~ /[^ ]*/ break=on-false
25e10655-a9b9-4447-bbe0-4c3081149afb Dialplan: sofia/external/767432661@172.20.100.3 Action export(companyid=4)
25e10655-a9b9-4447-bbe0-4c3081149afb Dialplan: sofia/external/767432661@172.20.100.3 Action export(tenantid=1)
25e10655-a9b9-4447-bbe0-4c3081149afb Dialplan: sofia/external/767432661@172.20.100.3 Action export(dvp_app_id=5)
25e10655-a9b9-4447-bbe0-4c3081149afb Dialplan: sofia/external/767432661@172.20.100.3 Action export(DVP_CALL_DIRECTION=inbound)
25e10655-a9b9-4447-bbe0-4c3081149afb Dialplan: sofia/external/767432661@172.20.100.3 Action set(effective_caller_id_number=767432661)
25e10655-a9b9-4447-bbe0-4c3081149afb Dialplan: sofia/external/767432661@172.20.100.3 Action set(DVP_OPERATION_CAT=HTTAPI)
25e10655-a9b9-4447-bbe0-4c3081149afb Dialplan: sofia/external/767432661@172.20.100.3 Action export(dvp_app_type=HTTAPI)
25e10655-a9b9-4447-bbe0-4c3081149afb Dialplan: sofia/external/767432661@172.20.100.3 Action answer()
25e10655-a9b9-4447-bbe0-4c3081149afb Dialplan: sofia/external/767432661@172.20.100.3 Action httapi({url=http://httpprogrammingapi.facetone.combank.lk/})
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_state_machine.c:286 (sofia/external/767432661@172.20.100.3) State Change CS_ROUTING -> CS_EXECUTE
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_state_machine.c:643 (sofia/external/767432661@172.20.100.3) State ROUTING going to sleep
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_state_machine.c:584 (sofia/external/767432661@172.20.100.3) Running State Change CS_EXECUTE (Cur 1 Tot 1)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_state_machine.c:650 (sofia/external/767432661@172.20.100.3) State EXECUTE
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] mod_sofia.c:198 sofia/external/767432661@172.20.100.3 SOFIA EXECUTE
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_state_machine.c:328 sofia/external/767432661@172.20.100.3 Standard EXECUTE
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 export(companyid=4)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [companyid]=[4]
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 export(tenantid=1)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [tenantid]=[1]
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 export(dvp_app_id=5)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dvp_app_id]=[5]
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 export(DVP_CALL_DIRECTION=inbound)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [DVP_CALL_DIRECTION]=[inbound]
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 set(effective_caller_id_number=767432661)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] mod_dptools.c:1530 SET sofia/external/767432661@172.20.100.3 [effective_caller_id_number]=[767432661]
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 set(DVP_OPERATION_CAT=HTTAPI)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] mod_dptools.c:1530 SET sofia/external/767432661@172.20.100.3 [DVP_OPERATION_CAT]=[HTTAPI]
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 export(dvp_app_type=HTTAPI)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dvp_app_type]=[HTTAPI]
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 answer()
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:3912 Activate Buggy RFC2833 Mode!
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:4361 Set telephone-event payload to 101@8000
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:3057 Set Codec sofia/external/767432661@172.20.100.3 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_codec.c:111 sofia/external/767432661@172.20.100.3 Original read codec set to PCMU:0
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:4704 Set telephone-event payload to 101@8000
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:4763 sofia/external/767432661@172.20.100.3 Set 2833 dtmf send payload to 101 recv payload to 101
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_core_media.c:6874 AUDIO RTP [sofia/external/767432661@172.20.100.3] 172.20.100.156 port 21788 -> 172.20.100.3 port 17184 codec: 0 ms: 20
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.841700 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.861653 [DEBUG] switch_core_media.c:7175 sofia/external/767432661@172.20.100.3 Set 2833 dtmf send payload to 101
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.861653 [DEBUG] switch_core_media.c:7182 sofia/external/767432661@172.20.100.3 Set 2833 dtmf receive payload to 101
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.861653 [DEBUG] switch_core_media.c:7205 sofia/external/767432661@172.20.100.3 Set rtp dtmf delay to 40
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.861653 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/767432661@172.20.100.3!
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.861653 [DEBUG] switch_channel.c:3474 (sofia/external/767432661@172.20.100.3) Callstate Change RINGING -> EARLY
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.861653 [DEBUG] switch_core_media.c:6857 Audio params are unchanged for sofia/external/767432661@172.20.100.3.
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.861653 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/767432661@172.20.100.3:
25e10655-a9b9-4447-bbe0-4c3081149afb v=0
25e10655-a9b9-4447-bbe0-4c3081149afb o=FreeSWITCH 1498011131 1498011132 IN IP4 172.20.100.156
25e10655-a9b9-4447-bbe0-4c3081149afb s=FreeSWITCH
25e10655-a9b9-4447-bbe0-4c3081149afb c=IN IP4 172.20.100.156
25e10655-a9b9-4447-bbe0-4c3081149afb t=0 0
25e10655-a9b9-4447-bbe0-4c3081149afb m=audio 21788 RTP/AVP 0 101
25e10655-a9b9-4447-bbe0-4c3081149afb a=rtpmap:0 PCMU/8000
25e10655-a9b9-4447-bbe0-4c3081149afb a=rtpmap:101 telephone-event/8000
25e10655-a9b9-4447-bbe0-4c3081149afb a=fmtp:101 0-16
25e10655-a9b9-4447-bbe0-4c3081149afb a=ptime:20
25e10655-a9b9-4447-bbe0-4c3081149afb a=sendrecv
25e10655-a9b9-4447-bbe0-4c3081149afb
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.861653 [NOTICE] mod_dptools.c:1312 Channel [sofia/external/767432661@172.20.100.3] has been answered
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.861653 [DEBUG] switch_channel.c:3773 (sofia/external/767432661@172.20.100.3) Callstate Change EARLY -> ACTIVE
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.861653 [DEBUG] sofia.c:7048 Channel sofia/external/767432661@172.20.100.3 entering state [completed][200]
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 httapi({url=http://httpprogrammingapi.facetone.combank.lk/})
2017-06-21 13:45:19.921638 [CRIT] mod_httapi.c:1160 Debugging Return Data:
<?xml version="1.0"?>
<document type="text/freeswitch-httapi">
<variables>
<tags>[object Object]</tags>
</variables>
<work>
<continue action="http://httpprogrammingapi.facetone.combank.lk"/>
</work>
</document>
2017-06-21 13:45:19.921638 [DEBUG] mod_httapi.c:1229 Process Tag: [continue]
2017-06-21 13:45:19.941642 [CRIT] mod_httapi.c:1160 Debugging Return Data:
<?xml version="1.0"?>
<document type="text/freeswitch-httapi">
<variables/>
<params/>
<work>
<getVariable action="http://httpprogrammingapi.facetone.combank.lk" temp-action="http://httpprogrammingapi.facetone.combank.lk" name="effective_caller_id_number" permanent="true"/>
</work>
</document>
2017-06-21 13:45:19.941642 [DEBUG] mod_httapi.c:1229 Process Tag: [getVariable]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:19.941642 [DEBUG] sofia.c:7048 Channel sofia/external/767432661@172.20.100.3 entering state [ready][200]
2017-06-21 13:45:20.001637 [CRIT] mod_httapi.c:1160 Debugging Return Data:
<?xml version="1.0"?>
<document type="text/freeswitch-httapi">
<variables/>
<params/>
<work>
<execute action="http://httpprogrammingapi.facetone.combank.lk" temp-action="http://httpprogrammingapi.facetone.combank.lk" application="play_and_get_digits" data="1 1 1 5000 # http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/Com_WelcomeDB.wav ./invalid.wav result \S{1}"/>
<getVariable name="result"/>
</work>
</document>
2017-06-21 13:45:20.001637 [DEBUG] mod_httapi.c:1229 Process Tag: [execute]
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 play_and_get_digits(1 1 1 5000 # http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/Com_WelcomeDB.wav ./invalid.wav result \S{1})
span style="color: goldenrod; font-weight: bold;"> 2017-06-21 13:45:20.021673 [DEBUG] mod_httapi.c:2640 caching: url:http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/Com_WelcomeDB.wav to /var/lib/freeswitch/storage/http_file_cache/2ee30b959a3effeba0fd010a9f7ac591.wav (167362 bytes)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:20.021673 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:20.021673 [DEBUG] switch_rtp.c:7254 Correct audio ip/port confirmed.
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:21.581729 [DEBUG] switch_rtp.c:7480 RTP RECV DTMF 1:904
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:21.581729 [INFO] switch_channel.c:515 RECV DTMF 1:904
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:21.581729 [DEBUG] switch_ivr_play_say.c:1942 done playing file http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/Com_WelcomeDB.wav
2017-06-21 13:45:21.601646 [DEBUG] mod_httapi.c:1229 Process Tag: [getVariable]
2017-06-21 13:45:21.601646 [CRIT] mod_httapi.c:1160 Debugging Return Data:
<?xml version="1.0"?>
<document type="text/freeswitch-httapi">
<variables>
<default_language>eng</default_language>
</variables>
<work>
<continue action="http://httpprogrammingapi.facetone.combank.lk"/>
</work>
</document>
2017-06-21 13:45:21.601646 [DEBUG] mod_httapi.c:1229 Process Tag: [continue]
2017-06-21 13:45:21.661710 [CRIT] mod_httapi.c:1160 Debugging Return Data:
<?xml version="1.0"?>
<document type="text/freeswitch-httapi">
<variables/>
<params/>
<work>
<execute action="http://httpprogrammingapi.facetone.combank.lk" temp-action="http://httpprogrammingapi.facetone.combank.lk" application="play_and_get_digits" data="1 1 1 5000 # http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/selectbankingoptionEng.wav ./invalid.wav 1 \S{1}"/>
<getVariable name="1"/>
</work>
</document>
2017-06-21 13:45:21.661710 [DEBUG] mod_httapi.c:1229 Process Tag: [execute]
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 play_and_get_digits(1 1 1 5000 # http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/selectbankingoptionEng.wav ./invalid.wav 1 \S{1})
span style="color: goldenrod; font-weight: bold;"> 2017-06-21 13:45:21.681645 [DEBUG] mod_httapi.c:2640 caching: url:http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/selectbankingoptionEng.wav to /var/lib/freeswitch/storage/http_file_cache/840249112939f1e74fa1031032a1d82c.wav (64658 bytes)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:21.701684 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:25.221696 [DEBUG] switch_rtp.c:7480 RTP RECV DTMF 1:824
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:25.221696 [INFO] switch_channel.c:515 RECV DTMF 1:824
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:25.221696 [DEBUG] switch_ivr_play_say.c:1942 done playing file http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/selectbankingoptionEng.wav
2017-06-21 13:45:25.241688 [DEBUG] mod_httapi.c:1229 Process Tag: [getVariable]
2017-06-21 13:45:25.281699 [CRIT] mod_httapi.c:1160 Debugging Return Data:
<?xml version="1.0"?>
<document type="text/freeswitch-httapi">
<variables/>
<params/>
<work>
<playback action="http://httpprogrammingapi.facetone.combank.lk" temp-action="http://httpprogrammingapi.facetone.combank.lk" name="result" file="http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/CallWillBeRecordedDBEng.wav" error-file="" digit-timeout="1" input-timeout="1" loops="0" terminators="#">
<bind strip="#">~\d{1}</bind>
</playback>
</work>
</document>
2017-06-21 13:45:25.281699 [DEBUG] mod_httapi.c:1229 Process Tag: [playback]
2017-06-21 13:45:25.281699 [INFO] switch_ivr_async.c:214 Digit parser HTTAPI: Setting realm to 'default'
2017-06-21 13:45:25.281699 [DEBUG] switch_ivr_async.c:320 Digit parser HTTAPI: binding \d{1}/default/0 callback: 0x7f8a248ff240 data: 0x7f89e004e7b8
2017-06-21 13:45:25.281699 [INFO] switch_ivr_async.c:214 Digit parser HTTAPI: Setting realm to 'default'
2017-06-21 13:45:25.281699 [DEBUG] switch_ivr_async.c:203 Digit parser HTTAPI: Setting terminators for realm 'default' to '#'
span style="color: goldenrod; font-weight: bold;"> 2017-06-21 13:45:25.301647 [DEBUG] mod_httapi.c:2640 caching: url:http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/CallWillBeRecordedDBEng.wav to /var/lib/freeswitch/storage/http_file_cache/e026ea7e5d1c644be8869a6c5952d80b.wav (32235 bytes)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:25.301647 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:29.301696 [DEBUG] switch_ivr_play_say.c:1942 done playing file http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/CallWillBeRecordedDBEng.wav
2017-06-21 13:45:29.381635 [CRIT] mod_httapi.c:1160 Debugging Return Data:
<?xml version="1.0"?>
<document type="text/freeswitch-httapi">
<variables>
<ards_skill>2,9</ards_skill>
<ards_priority>0</ards_priority>
<ards_skill_display>English</ards_skill_display>
<ards_max_queue_time>0</ards_max_queue_time>
<companyid>4</companyid>
<tenantid>1</tenantid>
<ards_hold_music>English.wav</ards_hold_music>
<ards_first_announcement/>
<ards_announcement/>
<ards_announcement_time/>
<ards_position_announcement>false</ards_position_announcement>
<ards_position_language>en</ards_position_language>
</variables>
<params/>
<work>
<execute action="http://httpprogrammingapi.facetone.combank.lk" temp-action="http://httpprogrammingapi.facetone.combank.lk" application="ards" data="2,9,1,4,"/>
</work>
</document>
2017-06-21 13:45:29.381635 [DEBUG] mod_httapi.c:1229 Process Tag: [execute]
25e10655-a9b9-4447-bbe0-4c3081149afb EXECUTE sofia/external/767432661@172.20.100.3 ards(2,9,1,4,)
2017-06-21 13:45:29.421705 [NOTICE] mod_ards.c:1784 Possition recived for 25e10655-a9b9-4447-bbe0-4c3081149afb and the position is 12017-06-21 13:45:29.461683 [DEBUG] mod_httapi.c:2640 caching: url:http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/English.wav to /var/lib/freeswitch/storage/http_file_cache/af9d0a5ca39a2fb1cedd873fc2387486.wav (1135879 bytes)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:29.461683 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:30.061699 [DEBUG] mod_ards.c:1324 OutBound Started
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:30.061699 [DEBUG] mod_ards.c:1359 Setting outbound caller_id_name to: 767432661
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:30.061699 [DEBUG] mod_ards.c:1360 Setting outbound caller_id_number to: 767432661
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:30.061699 [INFO] mod_ards.c:1361 Setting channel name to: sofia/external/767432661@172.20.100.3
2017-06-21 13:45:30.081648 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-06-21 13:45:30.121660 [DEBUG] switch_xml.c:2073 caching lookup for user 1004@172.20.100.156 indefinitely
2017-06-21 13:45:30.141651 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/sineth@192.168.116.35:5060 [8b0f74c6-86b4-46f2-b77e-c4e758a5932b]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] mod_sofia.c:4819 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_NEW -> CS_INIT
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_INIT (Cur 2 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/sineth@192.168.116.35:5060) State INIT
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] mod_sofia.c:90 sofia/internal/sineth@192.168.116.35:5060 SOFIA INIT
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] sofia_glue.c:1264 sip:sineth@192.168.116.35:5060 Setting proxy route to sofia/internal/sineth@192.168.116.35:5060
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] sofia_glue.c:1295 sofia/internal/sineth@192.168.116.35:5060 sending invite version: 1.6.18 -35-6e79667 64bit
8b0f74c6-86b4-46f2-b77e-c4e758a5932b Local SDP:
8b0f74c6-86b4-46f2-b77e-c4e758a5932b v=0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b o=FreeSWITCH 1498003506 1498003507 IN IP4 172.20.100.156
8b0f74c6-86b4-46f2-b77e-c4e758a5932b s=FreeSWITCH
8b0f74c6-86b4-46f2-b77e-c4e758a5932b c=IN IP4 172.20.100.156
8b0f74c6-86b4-46f2-b77e-c4e758a5932b t=0 0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b m=audio 29424 RTP/AVP 0 8 101
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=rtpmap:0 PCMU/8000
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=rtpmap:8 PCMA/8000
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=rtpmap:101 telephone-event/8000
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=fmtp:101 0-16
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=ptime:20
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=sendrecv
8b0f74c6-86b4-46f2-b77e-c4e758a5932b
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_core_state_machine.c:40 sofia/internal/sineth@192.168.116.35:5060 Standard INIT
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_INIT -> CS_ROUTING
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/sineth@192.168.116.35:5060) State INIT going to sleep
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_ROUTING (Cur 2 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/sineth@192.168.116.35:5060) State ROUTING
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] mod_sofia.c:143 sofia/internal/sineth@192.168.116.35:5060 SOFIA ROUTING
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/sineth@192.168.116.35:5060) State ROUTING going to sleep
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] sofia.c:7048 Channel sofia/internal/sineth@192.168.116.35:5060 entering state [calling][0]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/sineth@192.168.116.35:5060) State CONSUME_MEDIA
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.141651 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/sineth@192.168.116.35:5060) State CONSUME_MEDIA going to sleep
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.161645 [DEBUG] sofia.c:7048 Channel sofia/internal/sineth@192.168.116.35:5060 entering state [proceeding][180]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.161645 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/sineth@192.168.116.35:5060!
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:30.161645 [DEBUG] switch_channel.c:3346 (sofia/internal/sineth@192.168.116.35:5060) Callstate Change DOWN -> RINGING
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] sofia.c:7048 Channel sofia/internal/sineth@192.168.116.35:5060 entering state [completing][200]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] sofia.c:7058 Remote SDP:
8b0f74c6-86b4-46f2-b77e-c4e758a5932b v=0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b o=- 257604662 1 IN IP4 192.168.116.35
8b0f74c6-86b4-46f2-b77e-c4e758a5932b s=portsip.com
8b0f74c6-86b4-46f2-b77e-c4e758a5932b c=IN IP4 192.168.116.35
8b0f74c6-86b4-46f2-b77e-c4e758a5932b t=0 0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b m=audio 20004 RTP/AVP 0 8 101
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=rtpmap:0 PCMU/8000
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=rtpmap:8 PCMA/8000
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=rtpmap:101 telephone-event/8000
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=fmtp:101 0-16
8b0f74c6-86b4-46f2-b77e-c4e758a5932b
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] sofia.c:7048 Channel sofia/internal/sineth@192.168.116.35:5060 entering state [ready][200]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_media.c:4361 Set telephone-event payload to 101@8000
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_media.c:3057 Set Codec sofia/internal/sineth@192.168.116.35:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_codec.c:111 sofia/internal/sineth@192.168.116.35:5060 Original read codec set to PCMU:0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_media.c:4704 Set telephone-event payload to 101@8000
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_media.c:4763 sofia/internal/sineth@192.168.116.35:5060 Set 2833 dtmf send payload to 101 recv payload to 101
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_core_media.c:6874 AUDIO RTP [sofia/internal/sineth@192.168.116.35:5060] 172.20.100.156 port 29424 -> 192.168.116.35 port 20004 codec: 0 ms: 20
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.741638 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.761642 [DEBUG] switch_core_media.c:7175 sofia/internal/sineth@192.168.116.35:5060 Set 2833 dtmf send payload to 101
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.761642 [DEBUG] switch_core_media.c:7182 sofia/internal/sineth@192.168.116.35:5060 Set 2833 dtmf receive payload to 101
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.761642 [DEBUG] switch_core_media.c:7205 sofia/internal/sineth@192.168.116.35:5060 Set rtp dtmf delay to 40
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.761642 [NOTICE] sofia.c:8182 Channel [sofia/internal/sineth@192.168.116.35:5060] has been answered
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.761642 [DEBUG] switch_channel.c:3773 (sofia/internal/sineth@192.168.116.35:5060) Callstate Change RINGING -> ACTIVE
2017-06-21 13:45:35.761642 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/sineth@192.168.116.35:5060]
2017-06-21 13:45:35.761642 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/sineth@192.168.116.35:5060]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:35.781653 [DEBUG] switch_core_media_bug.c:945 Attaching BUG to sofia/external/767432661@172.20.100.3
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:35.781653 [DEBUG] switch_ivr_async.c:1500 No silence detection configured; assuming start of speech
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:35.801645 [ERR] mod_ards.c:1546 Agent leg binding
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:35.801645 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *3 execute_extension::att_xfer XML ARDSFeatures|1|4
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:35.801645 [ERR] mod_ards.c:1554 Agent leg binding
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:35.801645 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *6 execute_extension::att_xfer_outbound XML ARDSFeatures|1|4
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:35.801645 [ERR] mod_ards.c:1563 Agent leg binding
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:35.801645 [INFO] switch_ivr_async.c:4173 Bound B-Leg: *9 execute_extension::att_xfer_ivr XML ARDSFeatures|1|4
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:35.801645 [DEBUG] switch_ivr_bridge.c:2030 (sofia/external/767432661@172.20.100.3) State Change CS_EXECUTE -> CS_HIBERNATE
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] switch_ivr_bridge.c:2032 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_CONSUME_MEDIA -> CS_HIBERNATE
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_HIBERNATE (Cur 2 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/sineth@192.168.116.35:5060) State HIBERNATE
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] mod_sofia.c:180 sofia/internal/sineth@192.168.116.35:5060 SOFIA HIBERNATE
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] switch_ivr_bridge.c:984 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_HIBERNATE -> CS_RESET
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] switch_core_state_machine.c:665 (sofia/internal/sineth@192.168.116.35:5060) State HIBERNATE going to sleep
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_RESET (Cur 2 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/sineth@192.168.116.35:5060) State RESET
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] mod_sofia.c:161 sofia/internal/sineth@192.168.116.35:5060 SOFIA RESET
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] switch_ivr_bridge.c:969 sofia/internal/sineth@192.168.116.35:5060 CUSTOM RESET
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] switch_core_state_machine.c:188 sofia/internal/sineth@192.168.116.35:5060 Standard RESET
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:35.801645 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/sineth@192.168.116.35:5060) State RESET going to sleep
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:35.801645 [DEBUG] switch_ivr_play_say.c:1942 done playing file http://fileservice.facetone.combank.lk/DVP/API/1.0.0.0/InternalFileService/File/DownloadLatest/1/4/English.wav
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:650 (sofia/external/767432661@172.20.100.3) State EXECUTE going to sleep
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:584 (sofia/external/767432661@172.20.100.3) Running State Change CS_HIBERNATE (Cur 2 Tot 2)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:665 (sofia/external/767432661@172.20.100.3) State HIBERNATE
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] mod_sofia.c:180 sofia/external/767432661@172.20.100.3 SOFIA HIBERNATE
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_ivr_bridge.c:984 (sofia/external/767432661@172.20.100.3) State Change CS_HIBERNATE -> CS_RESET
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:665 (sofia/external/767432661@172.20.100.3) State HIBERNATE going to sleep
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:584 (sofia/external/767432661@172.20.100.3) Running State Change CS_RESET (Cur 2 Tot 2)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:646 (sofia/external/767432661@172.20.100.3) State RESET
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] mod_sofia.c:161 sofia/external/767432661@172.20.100.3 SOFIA RESET
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_ivr_bridge.c:969 sofia/external/767432661@172.20.100.3 CUSTOM RESET
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_ivr_bridge.c:976 (sofia/external/767432661@172.20.100.3) State Change CS_RESET -> CS_SOFT_EXECUTE
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:646 (sofia/external/767432661@172.20.100.3) State RESET going to sleep
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:584 (sofia/external/767432661@172.20.100.3) Running State Change CS_SOFT_EXECUTE (Cur 2 Tot 2)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:656 (sofia/external/767432661@172.20.100.3) State SOFT_EXECUTE
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] mod_sofia.c:637 SOFIA SOFT_EXECUTE
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.341646 [DEBUG] switch_ivr_bridge.c:994 sofia/external/767432661@172.20.100.3 CUSTOM SOFT_EXECUTE
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.341646 [DEBUG] switch_ivr_bridge.c:1026 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_RESET -> CS_SOFT_EXECUTE
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_SOFT_EXECUTE (Cur 2 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/sineth@192.168.116.35:5060) State SOFT_EXECUTE
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.341646 [DEBUG] mod_sofia.c:637 SOFIA SOFT_EXECUTE
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.341646 [DEBUG] switch_ivr_bridge.c:994 sofia/internal/sineth@192.168.116.35:5060 CUSTOM SOFT_EXECUTE
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:400 sofia/internal/sineth@192.168.116.35:5060 Standard SOFT_EXECUTE
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.341646 [DEBUG] switch_core_state_machine.c:656 (sofia/internal/sineth@192.168.116.35:5060) State SOFT_EXECUTE going to sleep
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.361660 [DEBUG] switch_ivr_bridge.c:1509 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_SOFT_EXECUTE -> CS_CONSUME_MEDIA
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.361660 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.361660 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/sineth@192.168.116.35:5060) State CONSUME_MEDIA
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.361660 [DEBUG] switch_ivr_bridge.c:933 sofia/internal/sineth@192.168.116.35:5060 CUSTOM HOLD
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.361660 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/sineth@192.168.116.35:5060) State CONSUME_MEDIA going to sleep
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.361660 [DEBUG] switch_ivr_bridge.c:1614 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.361660 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.361660 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/sineth@192.168.116.35:5060) State EXCHANGE_MEDIA
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.361660 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 13:45:41.361660 [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMU:0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 13:45:41.361660 [DEBUG] switch_rtp.c:7254 Correct audio ip/port confirmed.
2017-06-21 13:45:45.441709 [INFO] mod_shout.c:332 LAME 3.99.5 64bits (http://lame.sf.net)
2017-06-21 13:45:45.441709 [INFO] mod_shout.c:332 polyphase lowpass filter disabled
2017-06-21 13:46:40.301675 [CRIT] switch_core.c:2723 Declinatio Mortuus Obfirmo!
====================================================================================================================================================
FS_SLAVE LOG
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 04:14:21.607165 [NOTICE] switch_channel.c:1104 New Channel sofia/external/767432661@172.20.100.3 [25e10655-a9b9-4447-bbe0-4c3081149afb]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 04:14:21.607165 [NOTICE] switch_core_session.c:2226 Close Channel sofia/external/767432661@172.20.100.3 [CS_NEW]
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 04:14:21.607165 [DEBUG] switch_core_state_machine.c:741 (sofia/external/767432661@172.20.100.3) Running State Change CS_DESTROY (Cur 0 Tot 1)
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 04:14:21.607165 [DEBUG] switch_core_state_machine.c:751 (sofia/external/767432661@172.20.100.3) State DESTROY
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 04:14:21.607165 [DEBUG] mod_sofia.c:343 sofia/external/767432661@172.20.100.3 SOFIA DESTROY
25e10655-a9b9-4447-bbe0-4c3081149afb 2017-06-21 04:14:21.607165 [DEBUG] switch_core_state_machine.c:751 (sofia/external/767432661@172.20.100.3) State DESTROY going to sleep
2017-06-21 04:14:21.607165 [WARNING] switch_core_sqldb.c:2987 Invalid cdr data, call not recovered
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/sineth@192.168.116.35:5060 [8b0f74c6-86b4-46f2-b77e-c4e758a5932b]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [NOTICE] switch_channel.c:1102 Rename Channel sofia/internal/sineth@192.168.116.35:5060->sofia/internal/sineth@192.168.116.35:5060 [8b0f74c6-86b4-46f2-b77e-c4e758a5932b]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_core_media.c:3057 Set Codec sofia/internal/sineth@192.168.116.35:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_core_codec.c:111 sofia/internal/sineth@192.168.116.35:5060 Original read codec set to PCMU:0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_core_media.c:6874 AUDIO RTP [sofia/internal/sineth@192.168.116.35:5060] 172.20.100.156 port 29424 -> 192.168.116.35 port 20004 codec: 0 ms: 20
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_rtp.c:4108 Starting timer [soft] 160 bytes per 20ms
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_core_media.c:7175 sofia/internal/sineth@192.168.116.35:5060 Set 2833 dtmf send payload to 101
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_core_media.c:7182 sofia/internal/sineth@192.168.116.35:5060 Set 2833 dtmf receive payload to 101
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_core_media.c:7205 sofia/internal/sineth@192.168.116.35:5060 Set rtp dtmf delay to 40
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_core_sqldb.c:3041 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_NEW -> CS_INIT
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [NOTICE] switch_core_sqldb.c:3042 Resurrecting fallen channel sofia/internal/sineth@192.168.116.35:5060
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_INIT (Cur 1 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/sineth@192.168.116.35:5060) State INIT
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] mod_sofia.c:90 sofia/internal/sineth@192.168.116.35:5060 SOFIA INIT
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] sofia_glue.c:1264 sip:(null)@192.168.116.35:5060 Setting proxy route to sofia/internal/sineth@192.168.116.35:5060
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] sofia_glue.c:1295 sofia/internal/sineth@192.168.116.35:5060 sending invite version: 1.6.18 -35-6e79667 64bit
8b0f74c6-86b4-46f2-b77e-c4e758a5932b Local SDP:
8b0f74c6-86b4-46f2-b77e-c4e758a5932b v=0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b o=FreeSWITCH 1498003437 1498003439 IN IP4 172.20.100.156
8b0f74c6-86b4-46f2-b77e-c4e758a5932b s=FreeSWITCH
8b0f74c6-86b4-46f2-b77e-c4e758a5932b c=IN IP4 172.20.100.156
8b0f74c6-86b4-46f2-b77e-c4e758a5932b t=0 0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b m=audio 29424 RTP/AVP 0 101
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=rtpmap:0 PCMU/8000
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=rtpmap:101 telephone-event/0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=fmtp:101 0-16
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=ptime:20
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=sendrecv
8b0f74c6-86b4-46f2-b77e-c4e758a5932b
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_core_state_machine.c:40 sofia/internal/sineth@192.168.116.35:5060 Standard INIT
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.607165 [DEBUG] switch_core_state_machine.c:43 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_INIT -> CS_RESET
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.627178 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/sineth@192.168.116.35:5060) State INIT going to sleep
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.627178 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_RESET (Cur 1 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.627178 [DEBUG] sofia.c:7048 Channel sofia/internal/sineth@192.168.116.35:5060 entering state [calling][0]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.627178 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/sineth@192.168.116.35:5060) State RESET
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.627178 [DEBUG] mod_sofia.c:161 sofia/internal/sineth@192.168.116.35:5060 SOFIA RESET
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.627178 [DEBUG] switch_core_state_machine.c:188 sofia/internal/sineth@192.168.116.35:5060 Standard RESET
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.627178 [DEBUG] switch_core_state_machine.c:646 (sofia/internal/sineth@192.168.116.35:5060) State RESET going to sleep
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.907224 [DEBUG] sofia.c:7048 Channel sofia/internal/sineth@192.168.116.35:5060 entering state [completing][200]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.907224 [DEBUG] sofia.c:7058 Remote SDP:
8b0f74c6-86b4-46f2-b77e-c4e758a5932b v=0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b o=- 257604662 2 IN IP4 192.168.116.35
8b0f74c6-86b4-46f2-b77e-c4e758a5932b s=portsip.com
8b0f74c6-86b4-46f2-b77e-c4e758a5932b c=IN IP4 192.168.116.35
8b0f74c6-86b4-46f2-b77e-c4e758a5932b t=0 0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b m=audio 20004 RTP/AVP 0
8b0f74c6-86b4-46f2-b77e-c4e758a5932b a=rtpmap:0 PCMU/8000
8b0f74c6-86b4-46f2-b77e-c4e758a5932b
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.907224 [DEBUG] sofia.c:7048 Channel sofia/internal/sineth@192.168.116.35:5060 entering state [ready][200]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.947158 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.947158 [DEBUG] switch_core_media.c:4500 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.947158 [DEBUG] switch_core_media.c:4445 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.947158 [DEBUG] switch_core_media.c:4734 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.947158 [DEBUG] switch_core_media.c:4763 sofia/internal/sineth@192.168.116.35:5060 Set 2833 dtmf send payload to 101 recv payload to 101
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:14:21.947158 [DEBUG] switch_core_media.c:6857 Audio params are unchanged for sofia/internal/sineth@192.168.116.35:5060.
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.307218 [NOTICE] sofia.c:1012 Hangup sofia/internal/sineth@192.168.116.35:5060 [CS_RESET] [NORMAL_CLEARING]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.307218 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_HANGUP (Cur 1 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.307218 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/sineth@192.168.116.35:5060) Callstate Change DOWN -> HANGUP
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.307218 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/sineth@192.168.116.35:5060) State HANGUP
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.307218 [DEBUG] mod_sofia.c:438 Channel sofia/internal/sineth@192.168.116.35:5060 hanging up, cause: NORMAL_CLEARING
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.307218 [DEBUG] switch_core_state_machine.c:60 sofia/internal/sineth@192.168.116.35:5060 Standard HANGUP, cause: NORMAL_CLEARING
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.307218 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/sineth@192.168.116.35:5060) State HANGUP going to sleep
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.307218 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_HANGUP -> CS_REPORTING
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.307218 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_REPORTING (Cur 1 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.307218 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/sineth@192.168.116.35:5060) State REPORTING
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.307218 [INFO] mod_json_cdr.c:271 Process [8b0f74c6-86b4-46f2-b77e-c4e758a5932b.cdr.json]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.367218 [DEBUG] switch_core_state_machine.c:174 sofia/internal/sineth@192.168.116.35:5060 Standard REPORTING, cause: NORMAL_CLEARING
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.367218 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/sineth@192.168.116.35:5060) State REPORTING going to sleep
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.367218 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/sineth@192.168.116.35:5060) State Change CS_REPORTING -> CS_DESTROY
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.367218 [DEBUG] switch_core_session.c:1664 Session 2 (sofia/internal/sineth@192.168.116.35:5060) Locked, Waiting on external entities
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.367218 [NOTICE] switch_core_session.c:1682 Session 2 (sofia/internal/sineth@192.168.116.35:5060) Ended
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.367218 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/sineth@192.168.116.35:5060 [CS_DESTROY]
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.367218 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/sineth@192.168.116.35:5060) Running State Change CS_DESTROY (Cur 0 Tot 2)
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.367218 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/sineth@192.168.116.35:5060) State DESTROY
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.367218 [DEBUG] mod_sofia.c:343 sofia/internal/sineth@192.168.116.35:5060 SOFIA DESTROY
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.367218 [DEBUG] switch_core_state_machine.c:181 sofia/internal/sineth@192.168.116.35:5060 Standard DESTROY
8b0f74c6-86b4-46f2-b77e-c4e758a5932b 2017-06-21 04:15:03.367218 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/sineth@192.168.116.35:5060) State DESTROY going to sleep
==================================================================================================================================================
EXTERNAL Profile
<profile name="external">
<gateways>
<X-PRE-PROCESS cmd="include" data="external/*.xml"/>
</gateways>
<aliases>
</aliases>
<domains>
<domain name="all" alias="false" parse="true"/>
</domains>
<settings>
<param name="debug" value="0"/>
<param name="sip-trace" value="no"/>
<param name="sip-capture" value="no"/>
<param name="rfc2833-pt" value="101"/>
<param name="sip-port" value="$${external_sip_port}"/>
<param name="dialplan" value="XML"/>
<param name="context" value="public"/>
<param name="dtmf-duration" value="2000"/>
<param name="inbound-codec-prefs" value="$${global_codec_prefs}"/>
<param name="outbound-codec-prefs" value="$${outbound_codec_prefs}"/>
<param name="hold-music" value="$${hold_music}"/>
<param name="rtp-timer-name" value="soft"/>
<param name="rtp-rewrite-timestamps" value="true"/>
<param name="local-network-acl" value="localnet.auto"/>
<param name="manage-presence" value="false"/>
<param name="track-calls" value="true"/>
<param name="inbound-codec-negotiation" value="generous"/>
<param name="nonce-ttl" value="60"/>
<param name="auth-calls" value="false"/>
<param name="inbound-late-negotiation" value="true"/>
<param name="inbound-zrtp-passthru" value="true"/>
<param name="rtp-ip" value="172.20.100.156"/>
<param name="sip-ip" value="172.20.100.156"/>
<param name="ext-rtp-ip" value="172.20.100.156"/>
<param name="ext-sip-ip" value="172.20.100.156"/>
<param name="rtp-timeout-sec" value="300"/>
<param name="rtp-hold-timeout-sec" value="1800"/>
<param name="odbc-dsn" value="odbc://freeswitch:DB_User:DB_PWD"/>
<param name="tls" value="$${external_ssl_enable}"/>
<param name="tls-only" value="false"/>
<param name="tls-bind-params" value="transport=tls"/>
<param name="tls-sip-port" value="$${external_tls_port}"/>
<param name="tls-passphrase" value=""/>
<param name="tls-verify-date" value="true"/>
<param name="tls-verify-policy" value="none"/>
<param name="tls-verify-depth" value="2"/>
<param name="tls-verify-in-subjects" value=""/>
<param name="tls-version" value="$${sip_tls_version}"/>
</settings>
</profile>
=======================================================================================================================
INTERNAL Profile
<profile name="internal">
<aliases>
</aliases>
<gateways>
</gateways>
<domains>
<domain name="all" alias="true" parse="false"/>
</domains>
<settings>
<param name="debug" value="0"/>
<param name="sip-trace" value="no"/>
<param name="sip-capture" value="no"/>
<param name="watchdog-enabled" value="no"/>
<param name="watchdog-step-timeout" value="30000"/>
<param name="watchdog-event-timeout" value="30000"/>
<param name="log-auth-failures" value="false"/>
<param name="forward-unsolicited-mwi-notify" value="false"/>
<param name="context" value="public"/>
<param name="rfc2833-pt" value="101"/>
<param name="sip-port" value="$${internal_sip_port}"/>
<param name="dialplan" value="XML"/>
<param name="dtmf-duration" value="2000"/>
<param name="inbound-codec-prefs" value="$${global_codec_prefs}"/>
<param name="outbound-codec-prefs" value="$${global_codec_prefs}"/>
<param name="rtp-timer-name" value="soft"/>
<param name="rtp-ip" value="172.20.100.156"/>
<param name="sip-ip" value="172.20.100.156"/>
<param name="hold-music" value="$${hold_music}"/>
<param name="apply-nat-acl" value="nat.auto"/>
<param name="track-calls" value="true"/>
<param name="apply-candidate-acl" value="rfc1918.auto"/>
<param name="apply-inbound-acl" value="domains"/>
<param name="local-network-acl" value="localnet.auto"/>
<param name="record-path" value="$${recordings_dir}"/>
<param name="record-template" value="${caller_id_number}.${target_domain}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav"/>
<param name="manage-presence" value="true"/>
<param name="presence-hosts" value="172.20.100.156"/>
<param name="presence-privacy" value="$${presence_privacy}"/>
<param name="inbound-codec-negotiation" value="generous"/>
<param name="tls" value="$${internal_ssl_enable}"/>
<param name="tls-only" value="false"/>
<param name="tls-bind-params" value="transport=tls"/>
<param name="tls-sip-port" value="$${internal_tls_port}"/>
<param name="tls-passphrase" value=""/>
<param name="tls-verify-date" value="true"/>
<param name="tls-verify-policy" value="none"/>
<param name="tls-verify-depth" value="2"/>
<param name="tls-verify-in-subjects" value=""/>
<param name="tls-version" value="$${sip_tls_version}"/>
<param name="tls-ciphers" value="$${sip_tls_ciphers}"/>
<param name="odbc-dsn" value="odbc://freeswitch:DB_User:DB_PWD"/>
<param name="inbound-late-negotiation" value="true"/>
<param name="inbound-zrtp-passthru" value="true"/>
<param name="nonce-ttl" value="60"/>
<param name="auth-calls" value="$${internal_auth_calls}"/>
<param name="inbound-reg-force-matching-username" value="true"/>
<param name="auth-all-packets" value="false"/>
<param name="ext-rtp-ip" value="172.20.100.156"/>
<param name="ext-sip-ip" value="172.20.100.156"/>
<param name="rtp-timeout-sec" value="300"/>
<param name="rtp-hold-timeout-sec" value="1800"/>
<param name="force-register-domain" value="$${domain}"/>
<param name="force-subscription-domain" value="$${domain}"/>
<param name="force-register-db-domain" value="$${domain}"/>
<param name="ws-binding" value=":5066"/>
<param name="wss-binding" value=":7443"/>
<param name="challenge-realm" value="auto_from"/>
</settings>
</profile>
===================================================================================================================================
SWITCH.CONF.XML
<configuration name="switch.conf" description="Core Configuration">
<cli-keybindings>
<key name="1" value="help"/>
<key name="2" value="status"/>
<key name="3" value="show channels"/>
<key name="4" value="show calls"/>
<key name="5" value="sofia status"/>
<key name="6" value="reloadxml"/>
<key name="7" value="console loglevel 0"/>
<key name="8" value="console loglevel 7"/>
<key name="9" value="sofia status profile internal"/>
<key name="10" value="sofia profile internal siptrace on"/>
<key name="11" value="sofia profile internal siptrace off"/>
<key name="12" value="version"/>
</cli-keybindings>
<default-ptimes>
</default-ptimes>
<settings>
<param name="colorize-console" value="true"/>
<param name="dialplan-timestamps" value="false"/>
<param name="switchname" value="2"/>
<param name="max-db-handles" value="50"/>
<param name="db-handle-timeout" value="10"/>
<param name="max-sessions" value="1000"/>
<param name="sessions-per-second" value="30"/>
<param name="loglevel" value="debug"/>
<param name="mailer-app" value="sendmail"/>
<param name="mailer-app-args" value="-t"/>
<param name="dump-cores" value="yes"/>
<param name="rtp-enable-zrtp" value="false"/>
<param name="core-db-dsn" value="odbc://freeswitch:DB_User:DB_PWD"/>
<param name="core-recovery-db-dsn" value="odbc://freeswitch:DB_User:DB_PWD"/>
<param name="core-dbtype" value="PGSQL"/>
</settings>
</configuration>