freeswitch@ip-10-0-0-245> freeswitch@ip-10-0-0-245> freeswitch@ip-10-0-0-245> recv 1415 bytes from tcp/[10.0.0.26]:19113 at 14:25:29.092683: ------------------------------------------------------------------------ INVITE sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SIP/2.0 Via: SIP/2.0/TCP 104.34.194.130:49384;branch=z9hG4bK.~yovM~tl9;rport From: ;tag=q8jhJA8QA To: sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com CSeq: 20 INVITE Call-ID: uvJrwaoxC8 Max-Forwards: 70 Supported: replaces, outbound Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Content-Length: 549 Contact: ;+sip.instance="" X-callerLatitude: 32.1011897 X-callerLongitude: -96.624755 X-callerLocationDateTime: 2017-06-01 14:25:27 X-serviceRequest: doctor User-Agent: NGA911Android/3.2.6 (belle-sip/1.6.1) v=0 o=12132841480 1394 2602 IN IP4 10.0.0.26 s=Talk c=IN IP4 10.0.0.26 b=AS:380 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 4970 RTP/AVP 0 8 18 101 a=fmtp:18 annexb=yes a=rtpmap:101 telephone-event/8000 a=rtcp-fb:* ccm tmmbr m=video 14334 RTP/AVP 96 97 a=rtpmap:96 VP8/90000 a=rtpmap:97 H264/90000 a=fmtp:97 profile-level-id=42801F a=rtcp-fb:* ccm tmmbr a=rtcp-fb:96 nack pli a=rtcp-fb:96 nack sli a=rtcp-fb:96 ack rpsi a=rtcp-fb:96 ccm fir a=rtcp-fb:97 nack pli a=rtcp-fb:97 ccm fir ------------------------------------------------------------------------ send 422 bytes to tcp/[10.0.0.26]:19113 at 14:25:29.092928: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TCP 104.34.194.130:49384;branch=z9hG4bK.~yovM~tl9;rport=19113;received=10.0.0.26 From: ;tag=q8jhJA8QA To: sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Call-ID: uvJrwaoxC8 CSeq: 20 INVITE User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170109T225752Z~6fe1deda45~64bit Content-Length: 0 ------------------------------------------------------------------------ 2017-06-01 14:25:29.086533 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com [7df8cf62-0707-4e30-9a2e-7f95d5acd152] 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_NEW (Cur 1 Tot 21) 2017-06-01 14:25:29.086533 [DEBUG] sofia.c:9997 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com receiving invite from 10.0.0.26:19113 version: 1.9.0 git 6fe1ded 2017-01-09 22:57:52Z 64bit 2017-06-01 14:25:29.086533 [DEBUG] sofia.c:10109 IP 10.0.0.26 Approved by acl "domains[gate10-0-0-26@10.0.0.245]". Access Granted. 2017-06-01 14:25:29.086533 [DEBUG] sofia.c:10246 Authenticating user gate10-0-0-26@10.0.0.245 2017-06-01 14:25:29.086533 [DEBUG] sofia.c:7229 Channel sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com entering state [received][100] 2017-06-01 14:25:29.086533 [DEBUG] sofia.c:7239 Remote SDP: v=0 o=12132841480 1394 2602 IN IP4 10.0.0.26 s=Talk c=IN IP4 10.0.0.26 b=AS:380 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 4970 RTP/AVP 0 8 18 101 a=fmtp:18 annexb=yes a=rtpmap:101 telephone-event/8000 a=rtcp-fb:* ccm tmmbr m=video 14334 RTP/AVP 96 97 a=rtpmap:96 VP8/90000 a=rtpmap:97 H264/90000 a=fmtp:97 profile-level-id=42801F a=rtcp-fb:* ccm tmmbr a=rtcp-fb:96 nack pli a=rtcp-fb:96 nack sli a=rtcp-fb:96 ack rpsi a=rtcp-fb:96 ccm fir a=rtcp-fb:97 nack pli a=rtcp-fb:97 ccm fir 2017-06-01 14:25:29.086533 [DEBUG] sofia.c:7631 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State Change CS_NEW -> CS_INIT 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State NEW 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_INIT (Cur 1 Tot 21) 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State INIT 2017-06-01 14:25:29.086533 [DEBUG] mod_sofia.c:92 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SOFIA INIT 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:40 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Standard INIT 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State Change CS_INIT -> CS_ROUTING 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State INIT going to sleep 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_ROUTING (Cur 1 Tot 21) 2017-06-01 14:25:29.086533 [DEBUG] switch_channel.c:2249 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Callstate Change DOWN -> RINGING 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State ROUTING 2017-06-01 14:25:29.086533 [DEBUG] mod_sofia.c:145 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SOFIA ROUTING 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:236 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Standard ROUTING 2017-06-01 14:25:29.086533 [INFO] mod_dialplan_xml.c:637 Processing 12132841480 <12132841480>->12149119111 in context e911 Dialplan: sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com parsing [e911->911] continue=false Dialplan: sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Regex (PASS) [911] destination_number(12149119111) =~ /^1(\d{10})$/ break=on-false Dialplan: sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Action set(sip_nat_detected=false) Dialplan: sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Action python(dialplan) 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State Change CS_ROUTING -> CS_EXECUTE 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State ROUTING going to sleep 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_EXECUTE (Cur 1 Tot 21) 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State EXECUTE 2017-06-01 14:25:29.086533 [DEBUG] mod_sofia.c:200 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SOFIA EXECUTE 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:328 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Standard EXECUTE EXECUTE sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com set(sip_nat_detected=false) 2017-06-01 14:25:29.086533 [DEBUG] mod_dptools.c:1562 SET sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com [sip_nat_detected]=[false] EXECUTE sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com python(dialplan) 2017-06-01 14:25:29.086533 [NOTICE] mod_python.c:212 Invoking py module: dialplan 2017-06-01 14:25:29.086533 [ERR] mod_python.c:231 Error importing module 2017-06-01 14:25:29.086533 [ERR] mod_python.c:164 Python Error by calling script "dialplan": Message: expected an indented block (dialplan.py, line 128) 2017-06-01 14:25:29.086533 [NOTICE] switch_core_state_machine.c:385 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com has executed the last dialplan instruction, hanging up. 2017-06-01 14:25:29.086533 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com [CS_EXECUTE] [NORMAL_CLEARING] 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State EXECUTE going to sleep 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_HANGUP (Cur 1 Tot 21) 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Callstate Change RINGING -> HANGUP 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State HANGUP 2017-06-01 14:25:29.086533 [DEBUG] mod_sofia.c:440 Channel sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com hanging up, cause: NORMAL_CLEARING 2017-06-01 14:25:29.086533 [DEBUG] mod_sofia.c:579 Responding to INVITE with: 480 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:60 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Standard HANGUP, cause: NORMAL_CLEARING 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State HANGUP going to sleep 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State Change CS_HANGUP -> CS_REPORTING 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_REPORTING (Cur 1 Tot 21) send 1005 bytes to tcp/[10.0.0.26]:19113 at 14:25:29.096377: ------------------------------------------------------------------------ SIP/2.0 480 Temporarily Unavailable Via: SIP/2.0/TCP 104.34.194.130:49384;branch=z9hG4bK.~yovM~tl9;rport=19113;received=10.0.0.26 Max-Forwards: 70 From: ;tag=q8jhJA8QA To: ;tag=mtDQ33aUt97ye Call-ID: uvJrwaoxC8 CSeq: 20 INVITE User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170109T225752Z~6fe1deda45~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 Remote-Party-ID: "12149119111" ;party=calling;privacy=off;screen=no 2017-06-01 14:25:29.086533 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State REPORTING ------------------------------------------------------------------------ recv 540 bytes from tcp/[10.0.0.26]:19113 at 14:25:29.177680: ------------------------------------------------------------------------ ACK sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SIP/2.0 Via: SIP/2.0/TCP 104.34.194.130:49384;branch=z9hG4bK.~yovM~tl9;rport Call-ID: uvJrwaoxC8 From: ;tag=q8jhJA8QA To: ;tag=mtDQ33aUt97ye Contact: ;+sip.instance="" Max-Forwards: 70 CSeq: 20 ACK Content-Length: 0 ------------------------------------------------------------------------ 2017-06-01 14:25:29.266523 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML] 2017-06-01 14:25:29.266523 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML] 2017-06-01 14:25:31.426528 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML] 2017-06-01 14:25:31.426528 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML] recv 1415 bytes from tcp/[10.0.0.26]:19113 at 14:25:32.961674: ------------------------------------------------------------------------ INVITE sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SIP/2.0 Via: SIP/2.0/TCP 104.34.194.130:49384;branch=z9hG4bK.NR0T-~iUI;rport From: ;tag=Sp3s3vgzl To: sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com CSeq: 20 INVITE Call-ID: L~ZcU3sS4X Max-Forwards: 70 Supported: replaces, outbound Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Content-Length: 549 Contact: ;+sip.instance="" X-callerLatitude: 32.1011897 X-callerLongitude: -96.624755 X-callerLocationDateTime: 2017-06-01 14:25:31 X-serviceRequest: doctor User-Agent: NGA911Android/3.2.6 (belle-sip/1.6.1) v=0 o=12132841480 570 3365 IN IP4 10.0.0.26 s=Talk c=IN IP4 10.0.0.26 b=AS:380 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 25152 RTP/AVP 0 8 18 101 a=fmtp:18 annexb=yes a=rtpmap:101 telephone-event/8000 a=rtcp-fb:* ccm tmmbr m=video 47384 RTP/AVP 96 97 a=rtpmap:96 VP8/90000 a=rtpmap:97 H264/90000 a=fmtp:97 profile-level-id=42801F a=rtcp-fb:* ccm tmmbr a=rtcp-fb:96 nack pli a=rtcp-fb:96 nack sli a=rtcp-fb:96 ack rpsi a=rtcp-fb:96 ccm fir a=rtcp-fb:97 nack pli a=rtcp-fb:97 ccm fir ------------------------------------------------------------------------ send 422 bytes to tcp/[10.0.0.26]:19113 at 14:25:32.961922: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TCP 104.34.194.130:49384;branch=z9hG4bK.NR0T-~iUI;rport=19113;received=10.0.0.26 From: ;tag=Sp3s3vgzl To: sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Call-ID: L~ZcU3sS4X CSeq: 20 INVITE User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170109T225752Z~6fe1deda45~64bit Content-Length: 0 ------------------------------------------------------------------------ 2017-06-01 14:25:32.946540 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com [0d85fc56-6e3e-43d2-a11d-1ee19fa35234] 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_NEW (Cur 2 Tot 22) 2017-06-01 14:25:32.946540 [DEBUG] sofia.c:9997 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com receiving invite from 10.0.0.26:19113 version: 1.9.0 git 6fe1ded 2017-01-09 22:57:52Z 64bit 2017-06-01 14:25:32.946540 [DEBUG] sofia.c:10109 IP 10.0.0.26 Approved by acl "domains[gate10-0-0-26@10.0.0.245]". Access Granted. 2017-06-01 14:25:32.946540 [DEBUG] sofia.c:10246 Authenticating user gate10-0-0-26@10.0.0.245 2017-06-01 14:25:32.946540 [DEBUG] sofia.c:7229 Channel sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com entering state [received][100] 2017-06-01 14:25:32.946540 [DEBUG] sofia.c:7239 Remote SDP: v=0 o=12132841480 570 3365 IN IP4 10.0.0.26 s=Talk c=IN IP4 10.0.0.26 b=AS:380 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 25152 RTP/AVP 0 8 18 101 a=fmtp:18 annexb=yes a=rtpmap:101 telephone-event/8000 a=rtcp-fb:* ccm tmmbr m=video 47384 RTP/AVP 96 97 a=rtpmap:96 VP8/90000 a=rtpmap:97 H264/90000 a=fmtp:97 profile-level-id=42801F a=rtcp-fb:* ccm tmmbr a=rtcp-fb:96 nack pli a=rtcp-fb:96 nack sli a=rtcp-fb:96 ack rpsi a=rtcp-fb:96 ccm fir a=rtcp-fb:97 nack pli a=rtcp-fb:97 ccm fir 2017-06-01 14:25:32.946540 [DEBUG] sofia.c:7631 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State Change CS_NEW -> CS_INIT 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State NEW 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_INIT (Cur 2 Tot 22) 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State INIT 2017-06-01 14:25:32.946540 [DEBUG] mod_sofia.c:92 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SOFIA INIT 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:40 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Standard INIT 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State Change CS_INIT -> CS_ROUTING 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State INIT going to sleep 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_ROUTING (Cur 2 Tot 22) 2017-06-01 14:25:32.946540 [DEBUG] switch_channel.c:2249 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Callstate Change DOWN -> RINGING 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State ROUTING 2017-06-01 14:25:32.946540 [DEBUG] mod_sofia.c:145 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SOFIA ROUTING 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:236 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Standard ROUTING 2017-06-01 14:25:32.946540 [INFO] mod_dialplan_xml.c:637 Processing 12132841480 <12132841480>->12149119111 in context e911 Dialplan: sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com parsing [e911->911] continue=false Dialplan: sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Regex (PASS) [911] destination_number(12149119111) =~ /^1(\d{10})$/ break=on-false Dialplan: sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Action set(sip_nat_detected=false) Dialplan: sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Action python(dialplan) 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State Change CS_ROUTING -> CS_EXECUTE 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State ROUTING going to sleep 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_EXECUTE (Cur 2 Tot 22) 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State EXECUTE 2017-06-01 14:25:32.946540 [DEBUG] mod_sofia.c:200 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SOFIA EXECUTE 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:328 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Standard EXECUTE EXECUTE sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com set(sip_nat_detected=false) 2017-06-01 14:25:32.946540 [DEBUG] mod_dptools.c:1562 SET sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com [sip_nat_detected]=[false] EXECUTE sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com python(dialplan) 2017-06-01 14:25:32.946540 [NOTICE] mod_python.c:212 Invoking py module: dialplan 2017-06-01 14:25:32.946540 [ERR] mod_python.c:231 Error importing module 2017-06-01 14:25:32.946540 [ERR] mod_python.c:164 Python Error by calling script "dialplan": Message: expected an indented block (dialplan.py, line 128) 2017-06-01 14:25:32.946540 [NOTICE] switch_core_state_machine.c:385 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com has executed the last dialplan instruction, hanging up. 2017-06-01 14:25:32.946540 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com [CS_EXECUTE] [NORMAL_CLEARING] 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State EXECUTE going to sleep 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_HANGUP (Cur 2 Tot 22) 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Callstate Change RINGING -> HANGUP 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State HANGUP 2017-06-01 14:25:32.946540 [DEBUG] mod_sofia.c:440 Channel sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com hanging up, cause: NORMAL_CLEARING 2017-06-01 14:25:32.946540 [DEBUG] mod_sofia.c:579 Responding to INVITE with: 480 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:60 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Standard HANGUP, cause: NORMAL_CLEARING 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State HANGUP going to sleep 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State Change CS_HANGUP -> CS_REPORTING 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_REPORTING (Cur 2 Tot 22) send 1005 bytes to tcp/[10.0.0.26]:19113 at 14:25:32.965440: ------------------------------------------------------------------------ SIP/2.0 480 Temporarily Unavailable Via: SIP/2.0/TCP 104.34.194.130:49384;branch=z9hG4bK.NR0T-~iUI;rport=19113;received=10.0.0.26 Max-Forwards: 70 From: ;tag=Sp3s3vgzl To: ;tag=N36F5yUyQjyHa Call-ID: L~ZcU3sS4X CSeq: 20 INVITE User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170109T225752Z~6fe1deda45~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 Remote-Party-ID: "12149119111" ;party=calling;privacy=off;screen=no ------------------------------------------------------------------------ 2017-06-01 14:25:32.946540 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State REPORTING 2017-06-01 14:25:33.086522 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML] 2017-06-01 14:25:33.086522 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML] recv 540 bytes from tcp/[10.0.0.26]:19113 at 14:25:33.103146: ------------------------------------------------------------------------ ACK sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SIP/2.0 Via: SIP/2.0/TCP 104.34.194.130:49384;branch=z9hG4bK.NR0T-~iUI;rport Call-ID: L~ZcU3sS4X From: ;tag=Sp3s3vgzl To: ;tag=N36F5yUyQjyHa Contact: ;+sip.instance="" Max-Forwards: 70 CSeq: 20 ACK Content-Length: 0 ------------------------------------------------------------------------ 2017-06-01 14:25:33.586521 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML] 2017-06-01 14:25:33.586521 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML] freeswitch@ip-10-0-0-245> freeswitch@ip-10-0-0-245> freeswitch@ip-10-0-0-245> freeswitch@ip-10-0-0-245> freeswitch@ip-10-0-0-245> freeswitch@ip-10-0-0-245> 2017-06-01 14:25:35.366533 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML] 2017-06-01 14:25:35.366533 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML] 2017-06-01 14:25:35.766523 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML] 2017-06-01 14:25:35.766523 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML] 2017-06-01 14:25:35.766523 [ERR] mod_xml_cdr.c:418 Unable to post to web server, writing to file 2017-06-01 14:25:35.766523 [DEBUG] switch_core_state_machine.c:174 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Standard REPORTING, cause: NORMAL_CLEARING 2017-06-01 14:25:35.766523 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State REPORTING going to sleep 2017-06-01 14:25:35.766523 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State Change CS_REPORTING -> CS_DESTROY 2017-06-01 14:25:35.766523 [DEBUG] switch_core_session.c:1695 Session 21 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Locked, Waiting on external entities 2017-06-01 14:25:35.766523 [NOTICE] switch_core_session.c:1713 Session 21 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Ended 2017-06-01 14:25:35.766523 [NOTICE] switch_core_session.c:1717 Close Channel sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com [CS_DESTROY] 2017-06-01 14:25:35.766523 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) Running State Change CS_DESTROY (Cur 1 Tot 22) 2017-06-01 14:25:35.766523 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State DESTROY 2017-06-01 14:25:35.766523 [DEBUG] mod_sofia.c:345 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SOFIA DESTROY 2017-06-01 14:25:35.766523 [DEBUG] switch_core_state_machine.c:181 sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Standard DESTROY 2017-06-01 14:25:35.766523 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com) State DESTROY going to sleep 2017-06-01 14:25:37.546520 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML] 2017-06-01 14:25:37.546520 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML] recv 1416 bytes from tcp/[10.0.0.26]:19113 at 14:25:39.355115: ------------------------------------------------------------------------ INVITE sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com SIP/2.0 Via: SIP/2.0/TCP 104.34.194.130:49384;branch=z9hG4bK.23-pYygXa;rport From: ;tag=bbm0c17W0 To: sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com CSeq: 20 INVITE Call-ID: fQvc2ms6UT Max-Forwards: 70 Supported: replaces, outbound Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Content-Length: 550 Contact: ;+sip.instance="" X-callerLatitude: 32.1011897 X-callerLongitude: -96.624755 X-callerLocationDateTime: 2017-06-01 14:25:37 X-serviceRequest: doctor User-Agent: NGA911Android/3.2.6 (belle-sip/1.6.1) v=0 o=12132841480 3978 2614 IN IP4 10.0.0.26 s=Talk c=IN IP4 10.0.0.26 b=AS:380 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 61218 RTP/AVP 0 8 18 101 a=fmtp:18 annexb=yes a=rtpmap:101 telephone-event/8000 a=rtcp-fb:* ccm tmmbr m=video 29820 RTP/AVP 96 97 a=rtpmap:96 VP8/90000 a=rtpmap:97 H264/90000 a=fmtp:97 profile-level-id=42801F a=rtcp-fb:* ccm tmmbr a=rtcp-fb:96 nack pli a=rtcp-fb:96 nack sli a=rtcp-fb:96 ack rpsi a=rtcp-fb:96 ccm fir a=rtcp-fb:97 nack pli a=rtcp-fb:97 ccm fir ------------------------------------------------------------------------ send 422 bytes to tcp/[10.0.0.26]:19113 at 14:25:39.355365: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TCP 104.34.194.130:49384;branch=z9hG4bK.23-pYygXa;rport=19113;received=10.0.0.26 From: ;tag=bbm0c17W0 To: sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com Call-ID: fQvc2ms6UT CSeq: 20 INVITE User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170109T225752Z~6fe1deda45~64bit Content-Length: 0 ------------------------------------------------------------------------ 2017-06-01 14:25:39.346540 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com [40fec172-53a6-44e0-94f2-e073b54c19dd]