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: <sip:12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;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:12132841480@10.0.0.26:19113;transport=tcp>;+sip.instance="<urn:uuid:8737813e-5d59-4f16-b563-b7fa8ffbd161>"
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: <sip:12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;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": <type 'exceptions.IndentationError'>
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: <sip:12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;tag=q8jhJA8QA
To: <sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;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" <sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;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: <sip:12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;tag=q8jhJA8QA
To: <sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;tag=mtDQ33aUt97ye
Contact: <sip:12132841480@10.0.0.26:19113;transport=tcp>;+sip.instance="<urn:uuid:8737813e-5d59-4f16-b563-b7fa8ffbd161>"
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: <sip:12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;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:12132841480@10.0.0.26:19113;transport=tcp>;+sip.instance="<urn:uuid:8737813e-5d59-4f16-b563-b7fa8ffbd161>"
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: <sip:12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;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": <type 'exceptions.IndentationError'>
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: <sip:12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;tag=Sp3s3vgzl
To: <sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;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" <sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;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: <sip:12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;tag=Sp3s3vgzl
To: <sip:12149119111@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;tag=N36F5yUyQjyHa
Contact: <sip:12132841480@10.0.0.26:19113;transport=tcp>;+sip.instance="<urn:uuid:8737813e-5d59-4f16-b563-b7fa8ffbd161>"
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: <sip:12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;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:12132841480@10.0.0.26:19113;transport=tcp>;+sip.instance="<urn:uuid:8737813e-5d59-4f16-b563-b7fa8ffbd161>"
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: <sip:12132841480@E911LoadBalancer-473001725.us-west-2.elb.amazonaws.com>;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]