recv 956 bytes from udp/[106.76.208.110]:49663 at 17:51:22.661661: ------------------------------------------------------------------------ INVITE sip:1000@icc-tech.com:5020 SIP/2.0 Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---fea7e85e3d7ad879;rport Max-Forwards: 70 Contact: To: From: "Brian West";tag=cfc94962 Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 1 INVITE Allow: INVITE, ACK, CANCEL, BYE, REFER, INFO, NOTIFY, OPTIONS, UPDATE, PRACK, MESSAGE, SUBSCRIBE Content-Type: application/sdp Supported: replaces, 100rel User-Agent: Bria Stretto iOS release 5.2.4001 stamp 41079.41081 Content-Length: 329 v=0 o=- 1525974679157578 1 IN IP4 100.67.7.149 s=Cpc session c=IN IP4 100.67.7.149 t=0 0 m=audio 64218 RTP/AVP 120 18 0 8 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv ------------------------------------------------------------------------ 2018-05-10 17:51:22.658062 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1003@icc-tech.com:5020 [a7df158e-bc42-40d2-b61a-f366749fbaf6] 2018-05-10 17:51:22.658062 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@icc-tech.com:5020) Running State Change CS_NEW (Cur 1 Tot 30) 2018-05-10 17:51:22.658062 [DEBUG] sofia.c:10080 sofia/internal/1003@icc-tech.com:5020 receiving invite from 106.76.208.110:49663 version: 1.9.0 git a139bbd 2018-05-09 16:08:24Z 64bit 2018-05-10 17:51:22.658062 [DEBUG] sofia.c:10251 IP 106.76.208.110 Rejected by acl "domains". Falling back to Digest auth. send 903 bytes to udp/[106.76.208.110]:49663 at 17:51:22.662994: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---fea7e85e3d7ad879;rport=49663;received=106.76.208.110 From: "Brian West";tag=cfc94962 To: ;tag=Ue2UaSr7yHKFe Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~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 Proxy-Authenticate: Digest realm="icc-tech.com", nonce="b9660709-36c8-45de-a71c-99d8337a0f0a", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2018-05-10 17:51:22.658062 [DEBUG] sofia.c:2413 detaching session a7df158e-bc42-40d2-b61a-f366749fbaf6 2018-05-10 17:51:22.658062 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1003@icc-tech.com:5020) State NEW recv 956 bytes from udp/[106.76.208.110]:49663 at 17:51:22.762128: ------------------------------------------------------------------------ INVITE sip:1000@icc-tech.com:5020 SIP/2.0 Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---fea7e85e3d7ad879;rport Max-Forwards: 70 Contact: To: From: "Brian West";tag=cfc94962 Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 1 INVITE Allow: INVITE, ACK, CANCEL, BYE, REFER, INFO, NOTIFY, OPTIONS, UPDATE, PRACK, MESSAGE, SUBSCRIBE Content-Type: application/sdp Supported: replaces, 100rel User-Agent: Bria Stretto iOS release 5.2.4001 stamp 41079.41081 Content-Length: 329 v=0 o=- 1525974679157578 1 IN IP4 100.67.7.149 s=Cpc session c=IN IP4 100.67.7.149 t=0 0 m=audio 64218 RTP/AVP 120 18 0 8 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv ------------------------------------------------------------------------ send 903 bytes to udp/[106.76.208.110]:49663 at 17:51:22.762324: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---fea7e85e3d7ad879;rport=49663;received=106.76.208.110 From: "Brian West";tag=cfc94962 To: ;tag=Ue2UaSr7yHKFe Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~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 Proxy-Authenticate: Digest realm="icc-tech.com", nonce="b9660709-36c8-45de-a71c-99d8337a0f0a", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ recv 345 bytes from udp/[106.76.208.110]:49663 at 17:51:22.821412: ------------------------------------------------------------------------ ACK sip:1000@icc-tech.com:5020 SIP/2.0 Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---fea7e85e3d7ad879;rport Max-Forwards: 70 To: ;tag=Ue2UaSr7yHKFe From: "Brian West";tag=cfc94962 Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 1 ACK Content-Length: 0 ------------------------------------------------------------------------ recv 345 bytes from udp/[106.76.208.110]:49663 at 17:51:22.991311: ------------------------------------------------------------------------ ACK sip:1000@icc-tech.com:5020 SIP/2.0 Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---fea7e85e3d7ad879;rport Max-Forwards: 70 To: ;tag=Ue2UaSr7yHKFe From: "Brian West";tag=cfc94962 Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 1 ACK Content-Length: 0 ------------------------------------------------------------------------ recv 1221 bytes from udp/[106.76.208.110]:49663 at 17:51:23.081564: ------------------------------------------------------------------------ INVITE sip:1000@icc-tech.com:5020 SIP/2.0 Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---8332b03d7907781a;rport Max-Forwards: 70 Contact: To: From: "Brian West";tag=cfc94962 Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, BYE, REFER, INFO, NOTIFY, OPTIONS, UPDATE, PRACK, MESSAGE, SUBSCRIBE Content-Type: application/sdp Proxy-Authorization: Digest username="1003",realm="icc-tech.com",nonce="b9660709-36c8-45de-a71c-99d8337a0f0a",uri="sip:1000@icc-tech.com:5020",response="311c3acbbc374665bfc18dfe228f8fdb",cnonce="3074b2c0f27705e21e58561406cc9148",nc=00000001,qop=auth,algorithm=MD5 Supported: replaces, 100rel User-Agent: Bria Stretto iOS release 5.2.4001 stamp 41079.41081 Content-Length: 329 v=0 o=- 1525974679157578 1 IN IP4 100.67.7.149 s=Cpc session c=IN IP4 100.67.7.149 t=0 0 m=audio 64218 RTP/AVP 120 18 0 8 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv ------------------------------------------------------------------------ 2018-05-10 17:51:23.078072 [DEBUG] sofia.c:2522 Re-attaching to session a7df158e-bc42-40d2-b61a-f366749fbaf6 2018-05-10 17:51:23.078072 [DEBUG] sofia.c:10080 sofia/internal/1003@icc-tech.com:5020 receiving invite from 106.76.208.110:49663 version: 1.9.0 git a139bbd 2018-05-09 16:08:24Z 64bit 2018-05-10 17:51:23.078072 [DEBUG] sofia.c:10251 IP 106.76.208.110 Rejected by acl "domains". Falling back to Digest auth. 2018-05-10 17:51:23.078072 [DEBUG] sofia.c:11388 Setting NAT mode based on nat.auto 2018-05-10 17:51:23.078072 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [received][100] 2018-05-10 17:51:23.078072 [DEBUG] sofia.c:7301 Remote SDP: v=0 o=- 1525974679157578 1 IN IP4 100.67.7.149 s=Cpc session c=IN IP4 100.67.7.149 t=0 0 m=audio 64218 RTP/AVP 120 18 0 8 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2018-05-10 17:51:23.078072 [DEBUG] sofia.c:7695 (sofia/internal/1003@icc-tech.com:5020) State Change CS_NEW -> CS_INIT 2018-05-10 17:51:23.078072 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@icc-tech.com:5020) Running State Change CS_INIT (Cur 1 Tot 30) 2018-05-10 17:51:23.078072 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1003@icc-tech.com:5020) State INIT 2018-05-10 17:51:23.078072 [DEBUG] mod_sofia.c:93 sofia/internal/1003@icc-tech.com:5020 SOFIA INIT 2018-05-10 17:51:23.078072 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1003@icc-tech.com:5020 Standard INIT 2018-05-10 17:51:23.078072 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1003@icc-tech.com:5020) State Change CS_INIT -> CS_ROUTING 2018-05-10 17:51:23.078072 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1003@icc-tech.com:5020) State INIT going to sleep 2018-05-10 17:51:23.078072 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@icc-tech.com:5020) Running State Change CS_ROUTING (Cur 1 Tot 30) 2018-05-10 17:51:23.078072 [DEBUG] switch_channel.c:2249 (sofia/internal/1003@icc-tech.com:5020) Callstate Change DOWN -> RINGING 2018-05-10 17:51:23.078072 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@icc-tech.com:5020) State ROUTING send 400 bytes to udp/[106.76.208.110]:49663 at 17:51:23.086652: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---8332b03d7907781a;rport=49663;received=106.76.208.110 From: "Brian West";tag=cfc94962 To: Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 2 INVITE User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit Content-Length: 0 ------------------------------------------------------------------------ 2018-05-10 17:51:23.078072 [DEBUG] mod_sofia.c:154 sofia/internal/1003@icc-tech.com:5020 SOFIA ROUTING 2018-05-10 17:51:23.078072 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1003@icc-tech.com:5020 Standard ROUTING 2018-05-10 17:51:23.078072 [INFO] mod_dialplan_xml.c:637 Processing Brian West <1003>->1000 in context default Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->unloop] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->tod_example] continue=true Dialplan: sofia/internal/1003@icc-tech.com:5020 Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(open=true) Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1003@icc-tech.com:5020 Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [global-intercept] destination_number(1000) =~ /^886$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [group-intercept] destination_number(1000) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [intercept-ext] destination_number(1000) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->redial] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [redial] destination_number(1000) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->global] continue=true Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [global] ${default_password}(12345) =~ /^1234$/ break=never Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [global] ${switch_r_sdp}(v=0 o=- 1525974679157578 1 IN IP4 100.67.7.149 s=Cpc session c=IN IP4 100.67.7.149 t=0 0 m=audio 64218 RTP/AVP 120 18 0 8 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never Dialplan: sofia/internal/1003@icc-tech.com:5020 Absolute Condition [global] Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [snom-demo-2] destination_number(1000) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [snom-demo-1] destination_number(1000) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [eavesdrop] destination_number(1000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [eavesdrop] destination_number(1000) =~ /^779$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->call_return] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [call_return] destination_number(1000) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->del-group] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [del-group] destination_number(1000) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->add-group] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [add-group] destination_number(1000) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [call-group-simo] destination_number(1000) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [call-group-order] destination_number(1000) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [extension-intercom] destination_number(1000) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (PASS) [Local_Extension] destination_number(1000) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1003@icc-tech.com:5020 Action export(dialed_extension=1000) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bind_meta_app(4 b s execute_extension::att_xfer XML features) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(ringback=${us-ring}) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(call_timeout=30) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(hangup_after_bridge=true) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(continue_on_fail=true) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid}) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action answer() Dialplan: sofia/internal/1003@icc-tech.com:5020 Action sleep(1000) Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) 2018-05-10 17:51:23.078072 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1003@icc-tech.com:5020) State Change CS_ROUTING -> CS_EXECUTE 2018-05-10 17:51:23.078072 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@icc-tech.com:5020) State ROUTING going to sleep 2018-05-10 17:51:23.088018 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@icc-tech.com:5020) Running State Change CS_EXECUTE (Cur 1 Tot 30) 2018-05-10 17:51:23.088018 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1003@icc-tech.com:5020) State EXECUTE 2018-05-10 17:51:23.088018 [DEBUG] mod_sofia.c:209 sofia/internal/1003@icc-tech.com:5020 SOFIA EXECUTE 2018-05-10 17:51:23.088018 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1003@icc-tech.com:5020 Standard EXECUTE EXECUTE sofia/internal/1003@icc-tech.com:5020 set(open=true) 2018-05-10 17:51:23.088018 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [open]=[true] EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-spymap/1003/a7df158e-bc42-40d2-b61a-f366749fbaf6) EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial/1003/1000) EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial/global/a7df158e-bc42-40d2-b61a-f366749fbaf6) EXECUTE sofia/internal/1003@icc-tech.com:5020 export(RFC2822_DATE=Thu, 10 May 2018 17:51:23 +0000) 2018-05-10 17:51:23.088018 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 10 May 2018 17:51:23 +0000] EXECUTE sofia/internal/1003@icc-tech.com:5020 export(dialed_extension=1000) 2018-05-10 17:51:23.088018 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1000] EXECUTE sofia/internal/1003@icc-tech.com:5020 bind_meta_app(1 b s execute_extension::dx XML features) 2018-05-10 17:51:23.088018 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *1 execute_extension::dx XML features EXECUTE sofia/internal/1003@icc-tech.com:5020 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1003.2018-05-10-17-51-23.wav) 2018-05-10 17:51:23.088018 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1003.2018-05-10-17-51-23.wav EXECUTE sofia/internal/1003@icc-tech.com:5020 bind_meta_app(3 b s execute_extension::cf XML features) 2018-05-10 17:51:23.088018 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *3 execute_extension::cf XML features EXECUTE sofia/internal/1003@icc-tech.com:5020 bind_meta_app(4 b s execute_extension::att_xfer XML features) 2018-05-10 17:51:23.088018 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *4 execute_extension::att_xfer XML features EXECUTE sofia/internal/1003@icc-tech.com:5020 set(ringback=%(2000,4000,440,480)) 2018-05-10 17:51:23.088018 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [ringback]=[%(2000,4000,440,480)] EXECUTE sofia/internal/1003@icc-tech.com:5020 set(transfer_ringback=local_stream://moh) 2018-05-10 17:51:23.088018 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/1003@icc-tech.com:5020 set(call_timeout=30) 2018-05-10 17:51:23.088018 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [call_timeout]=[30] EXECUTE sofia/internal/1003@icc-tech.com:5020 set(hangup_after_bridge=true) 2018-05-10 17:51:23.088018 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [hangup_after_bridge]=[true] EXECUTE sofia/internal/1003@icc-tech.com:5020 set(continue_on_fail=true) 2018-05-10 17:51:23.088018 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [continue_on_fail]=[true] EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-call_return/1000/1003) EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial_ext/1000/a7df158e-bc42-40d2-b61a-f366749fbaf6) EXECUTE sofia/internal/1003@icc-tech.com:5020 set(called_party_callgroup=techsupport) 2018-05-10 17:51:23.088018 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [called_party_callgroup]=[techsupport] EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial_ext/techsupport/a7df158e-bc42-40d2-b61a-f366749fbaf6) EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial_ext/global/a7df158e-bc42-40d2-b61a-f366749fbaf6) EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial/techsupport/a7df158e-bc42-40d2-b61a-f366749fbaf6) EXECUTE sofia/internal/1003@icc-tech.com:5020 bridge(user/1000@159.89.163.195) 2018-05-10 17:51:23.088018 [DEBUG] switch_channel.c:1250 sofia/internal/1003@icc-tech.com:5020 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 10 May 2018 17:51:23 +0000] to event 2018-05-10 17:51:23.088018 [DEBUG] switch_channel.c:1250 sofia/internal/1003@icc-tech.com:5020 EXPORTING[export_vars] [dialed_extension]=[1000] to event 2018-05-10 17:51:23.088018 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables 2018-05-10 17:51:23.088018 [DEBUG] switch_channel.c:1250 sofia/internal/1003@icc-tech.com:5020 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 10 May 2018 17:51:23 +0000] to event 2018-05-10 17:51:23.088018 [DEBUG] switch_channel.c:1250 sofia/internal/1003@icc-tech.com:5020 EXPORTING[export_vars] [dialed_extension]=[1000] to event 2018-05-10 17:51:23.088018 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables 2018-05-10 17:51:23.088018 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@124.123.68.233:21102 [5e6e3045-9f9b-4caf-b743-1b2a189029dc] 2018-05-10 17:51:23.088018 [DEBUG] mod_sofia.c:5028 (sofia/internal/1000@124.123.68.233:21102) State Change CS_NEW -> CS_INIT 2018-05-10 17:51:23.088018 [NOTICE] switch_ivr_originate.c:2868 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED] 2018-05-10 17:51:23.098016 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@124.123.68.233:21102) Running State Change CS_INIT (Cur 2 Tot 31) 2018-05-10 17:51:23.098016 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@124.123.68.233:21102) State INIT 2018-05-10 17:51:23.098016 [DEBUG] mod_sofia.c:93 sofia/internal/1000@124.123.68.233:21102 SOFIA INIT 2018-05-10 17:51:23.098016 [DEBUG] sofia_glue.c:1299 sofia/internal/1000@124.123.68.233:21102 sending invite version: 1.9.0 git a139bbd 2018-05-09 16:08:24Z 64bit Local SDP: v=0 o=FreeSWITCH 1525954505 1525954506 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 20178 RTP/AVP 102 0 8 103 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:103 telephone-event/48000 a=fmtp:103 0-16 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv send 1484 bytes to udp/[124.123.68.233]:21102 at 17:51:23.099537: ------------------------------------------------------------------------ INVITE sip:1000@124.123.68.233:21102;rinstance=f72e49e8403a7e5f SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bK8g5e6B3yccaNp Max-Forwards: 69 From: "Extension 1003" ;tag=X0mDeFteS3ZmN To: Call-ID: 9818cb57-cf1d-1236-a889-528373432f88 CSeq: 122651277 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit 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 Content-Type: application/sdp Content-Disposition: session Content-Length: 457 X-FS-Support: update_display,send_info Remote-Party-ID: "Extension 1003" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1525954505 1525954506 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 20178 RTP/AVP 102 0 8 103 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:103 telephone-event/48000 a=fmtp:103 0-16 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2018-05-10 17:51:23.098016 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@124.123.68.233:21102 Standard INIT 2018-05-10 17:51:23.098016 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@124.123.68.233:21102) State Change CS_INIT -> CS_ROUTING 2018-05-10 17:51:23.098016 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@124.123.68.233:21102) State INIT going to sleep 2018-05-10 17:51:23.098016 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@124.123.68.233:21102) Running State Change CS_ROUTING (Cur 2 Tot 31) 2018-05-10 17:51:23.098016 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [calling][0] 2018-05-10 17:51:23.098016 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@124.123.68.233:21102) State ROUTING 2018-05-10 17:51:23.098016 [DEBUG] mod_sofia.c:154 sofia/internal/1000@124.123.68.233:21102 SOFIA ROUTING 2018-05-10 17:51:23.098016 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@124.123.68.233:21102) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-05-10 17:51:23.098016 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@124.123.68.233:21102) State ROUTING going to sleep 2018-05-10 17:51:23.098016 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@124.123.68.233:21102) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 31) 2018-05-10 17:51:23.098016 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@124.123.68.233:21102) State CONSUME_MEDIA 2018-05-10 17:51:23.098016 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@124.123.68.233:21102) State CONSUME_MEDIA going to sleep recv 321 bytes from udp/[124.123.68.233]:21102 at 17:51:23.201475: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 159.89.163.195:5020;rport=5020;branch=z9hG4bK8g5e6B3yccaNp To: From: "Extension 1003" ;tag=X0mDeFteS3ZmN Call-ID: 9818cb57-cf1d-1236-a889-528373432f88 CSeq: 122651277 INVITE Content-Length: 0 ------------------------------------------------------------------------ recv 490 bytes from udp/[124.123.68.233]:21102 at 17:51:23.603599: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 159.89.163.195:5020;rport=5020;branch=z9hG4bK8g5e6B3yccaNp Contact: To: "shashi";tag=03fadd26 From: "Extension 1003" ;tag=X0mDeFteS3ZmN Call-ID: 9818cb57-cf1d-1236-a889-528373432f88 CSeq: 122651277 INVITE User-Agent: Bria Stretto release 5.2.0 stamp 90726 Allow-Events: talk, hold Content-Length: 0 ------------------------------------------------------------------------ 2018-05-10 17:51:23.598065 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [proceeding][180] 2018-05-10 17:51:23.598065 [NOTICE] sofia.c:7401 Ring-Ready sofia/internal/1000@124.123.68.233:21102! 2018-05-10 17:51:23.598065 [DEBUG] switch_channel.c:3354 (sofia/internal/1000@124.123.68.233:21102) Callstate Change DOWN -> RINGING 2018-05-10 17:51:23.618112 [INFO] switch_ivr_originate.c:1220 Sending early media 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:120:48000:20:0:1]/[opus:116:48000:20:0:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:120:48000:20:0:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000 2018-05-10 17:51:23.618112 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps] 2018-05-10 17:51:23.618112 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps] 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:3773 Set Codec sofia/internal/1003@icc-tech.com:5020 opus/48000 20 ms 960 samples 0 bits 1 channels 2018-05-10 17:51:23.618112 [DEBUG] switch_core_codec.c:111 sofia/internal/1003@icc-tech.com:5020 Original read codec set to opus:116 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:5775 sofia/internal/1003@icc-tech.com:5020 Set 2833 dtmf send payload to 101 recv payload to 101 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:8491 AUDIO RTP [sofia/internal/1003@icc-tech.com:5020] 159.89.163.195 port 28270 -> 100.67.7.149 port 64218 codec: 120 ms: 20 2018-05-10 17:51:23.618112 [DEBUG] switch_rtp.c:4277 Starting timer [soft] 960 bytes per 20ms 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:8795 sofia/internal/1003@icc-tech.com:5020 Set 2833 dtmf send payload to 101 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:8802 sofia/internal/1003@icc-tech.com:5020 Set 2833 dtmf receive payload to 101 2018-05-10 17:51:23.618112 [DEBUG] switch_core_media.c:8825 sofia/internal/1003@icc-tech.com:5020 Set rtp dtmf delay to 40 2018-05-10 17:51:23.618112 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1003@icc-tech.com:5020! 2018-05-10 17:51:23.618112 [DEBUG] switch_channel.c:3482 (sofia/internal/1003@icc-tech.com:5020) Callstate Change RINGING -> EARLY 2018-05-10 17:51:23.628079 [DEBUG] switch_core_media.c:8474 Audio params are unchanged for sofia/internal/1003@icc-tech.com:5020. 2018-05-10 17:51:23.628079 [DEBUG] mod_sofia.c:2514 Ring SDP: v=0 o=FreeSWITCH 1525946413 1525946414 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 28270 RTP/AVP 120 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv send 1229 bytes to udp/[106.76.208.110]:49663 at 17:51:23.628562: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---8332b03d7907781a;rport=49663;received=106.76.208.110 From: "Brian West";tag=cfc94962 To: ;tag=vQUmcm9avt91S Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 2 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~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 Content-Type: application/sdp Content-Disposition: session Content-Length: 258 Remote-Party-ID: "1000" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1525946413 1525946414 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 28270 RTP/AVP 120 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2018-05-10 17:51:23.628079 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [early][183] 2018-05-10 17:51:23.628079 [DEBUG] switch_ivr_originate.c:1278 Raw Codec Activation Success L16@48000hz 1 channel 20ms 2018-05-10 17:51:23.628079 [DEBUG] switch_core_codec.c:223 sofia/internal/1003@icc-tech.com:5020 Push codec L16:100 2018-05-10 17:51:23.628079 [DEBUG] switch_ivr_originate.c:1347 Play Ringback Tone [%(2000,4000,440,480)] 2018-05-10 17:51:24.978060 [INFO] switch_rtp.c:7450 Auto Changing audio port from 100.67.7.149:64218 to 106.76.208.110:64218 recv 894 bytes from udp/[124.123.68.233]:21102 at 17:51:27.092968: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 159.89.163.195:5020;rport=5020;branch=z9hG4bK8g5e6B3yccaNp Contact: To: ;tag=03fadd26 From: "Extension 1003" ;tag=X0mDeFteS3ZmN Call-ID: 9818cb57-cf1d-1236-a889-528373432f88 CSeq: 122651277 INVITE Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE Content-Type: application/sdp Supported: replaces User-Agent: Bria Stretto release 5.2.0 stamp 90726 Content-Length: 306 v=0 o=- 3816328869 3 IN IP4 10.144.160.39 s=Bria Stretto release 5.2.0 stamp 90726 c=IN IP4 124.123.68.233 t=0 0 m=audio 21231 RTP/AVP 102 0 8 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv ------------------------------------------------------------------------ 2018-05-10 17:51:27.088021 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [completing][200] 2018-05-10 17:51:27.088021 [DEBUG] sofia.c:7301 Remote SDP: v=0 o=- 3816328869 3 IN IP4 10.144.160.39 s=Bria Stretto release 5.2.0 stamp 90726 c=IN IP4 124.123.68.233 t=0 0 m=audio 21231 RTP/AVP 102 0 8 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2018-05-10 17:51:27.088021 [NOTICE] sofia.c:7304 Pre-Answer sofia/internal/1000@124.123.68.233:21102! 2018-05-10 17:51:27.088021 [DEBUG] switch_channel.c:3482 (sofia/internal/1000@124.123.68.233:21102) Callstate Change RINGING -> EARLY send 440 bytes to udp/[124.123.68.233]:21102 at 17:51:27.095857: ------------------------------------------------------------------------ ACK sip:1000@124.123.68.233:21102;rinstance=f72e49e8403a7e5f SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bK9Sy776K29m07H Max-Forwards: 70 From: "Extension 1003" ;tag=X0mDeFteS3ZmN To: ;tag=03fadd26 Call-ID: 9818cb57-cf1d-1236-a889-528373432f88 CSeq: 122651277 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ 2018-05-10 17:51:27.088021 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [ready][200] 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[opus:116:48000:20:0:2] 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [opus:116:48000:20:0:2] ++++ is saved as a match 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:2] 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:2] 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000 2018-05-10 17:51:27.088021 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps] 2018-05-10 17:51:27.088021 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps] 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:3773 Set Codec sofia/internal/1000@124.123.68.233:21102 opus/48000 20 ms 960 samples 0 bits 1 channels 2018-05-10 17:51:27.088021 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@124.123.68.233:21102 Original read codec set to opus:116 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:5775 sofia/internal/1000@124.123.68.233:21102 Set 2833 dtmf send payload to 101 recv payload to 101 2018-05-10 17:51:27.088021 [DEBUG] switch_core_media.c:8491 AUDIO RTP [sofia/internal/1000@124.123.68.233:21102] 159.89.163.195 port 20178 -> 124.123.68.233 port 21231 codec: 102 ms: 20 2018-05-10 17:51:27.088021 [DEBUG] switch_rtp.c:4277 Starting timer [soft] 960 bytes per 20ms 2018-05-10 17:51:27.098038 [DEBUG] switch_core_media.c:8795 sofia/internal/1000@124.123.68.233:21102 Set 2833 dtmf send payload to 101 2018-05-10 17:51:27.098038 [DEBUG] switch_core_media.c:8802 sofia/internal/1000@124.123.68.233:21102 Set 2833 dtmf receive payload to 101 2018-05-10 17:51:27.098038 [DEBUG] switch_core_media.c:8825 sofia/internal/1000@124.123.68.233:21102 Set rtp dtmf delay to 40 2018-05-10 17:51:27.098038 [NOTICE] sofia.c:8429 Channel [sofia/internal/1000@124.123.68.233:21102] has been answered 2018-05-10 17:51:27.098038 [DEBUG] switch_channel.c:3781 (sofia/internal/1000@124.123.68.233:21102) Callstate Change EARLY -> ACTIVE 2018-05-10 17:51:27.098038 [DEBUG] switch_core_codec.c:248 sofia/internal/1003@icc-tech.com:5020 Restore previous codec opus:116. 2018-05-10 17:51:27.098038 [DEBUG] switch_core_media.c:8474 Audio params are unchanged for sofia/internal/1003@icc-tech.com:5020. 2018-05-10 17:51:27.098038 [DEBUG] mod_sofia.c:881 Local SDP sofia/internal/1003@icc-tech.com:5020: v=0 o=FreeSWITCH 1525946413 1525946415 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 28270 RTP/AVP 120 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv send 1235 bytes to udp/[106.76.208.110]:49663 at 17:51:27.106548: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---8332b03d7907781a;rport=49663;received=106.76.208.110 From: "Brian West";tag=cfc94962 To: ;tag=vQUmcm9avt91S Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 2 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit 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 Session-Expires: 120;refresher=uas Content-Type: application/sdp Content-Disposition: session Content-Length: 258 Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1525946413 1525946414 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 28270 RTP/AVP 120 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2018-05-10 17:51:27.098038 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [completed][200] 2018-05-10 17:51:27.098038 [NOTICE] switch_ivr_originate.c:3664 Channel [sofia/internal/1003@icc-tech.com:5020] has been answered 2018-05-10 17:51:27.108016 [DEBUG] switch_channel.c:3781 (sofia/internal/1003@icc-tech.com:5020) Callstate Change EARLY -> ACTIVE 2018-05-10 17:51:27.108016 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [sofia/internal/1000@124.123.68.233:21102] 2018-05-10 17:51:27.108016 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [sofia/internal/1000@124.123.68.233:21102] 2018-05-10 17:51:27.108016 [DEBUG] switch_ivr_bridge.c:1744 (sofia/internal/1000@124.123.68.233:21102) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2018-05-10 17:51:27.108016 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@124.123.68.233:21102) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 31) 2018-05-10 17:51:27.108016 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1000@124.123.68.233:21102) State EXCHANGE_MEDIA 2018-05-10 17:51:27.108016 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA 2018-05-10 17:51:27.138068 [DEBUG] switch_rtp.c:7490 Correct audio ip/port confirmed. 2018-05-10 17:51:27.138068 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 2018-05-10 17:51:27.138068 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 2018-05-10 17:51:27.138068 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps] 2018-05-10 17:51:27.148035 [DEBUG] switch_rtp.c:7490 Correct audio ip/port confirmed. 2018-05-10 17:51:27.148035 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 2018-05-10 17:51:27.148035 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 2018-05-10 17:51:27.148035 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps] recv 495 bytes from udp/[106.76.208.110]:49663 at 17:51:27.261476: ------------------------------------------------------------------------ ACK sip:1000@159.89.163.195:5020;transport=udp SIP/2.0 Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---cfe29338297b9b68;rport Max-Forwards: 70 Contact: To: ;tag=vQUmcm9avt91S From: "Brian West";tag=cfc94962 Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 2 ACK User-Agent: Bria Stretto iOS release 5.2.4001 stamp 41079.41081 Content-Length: 0 ------------------------------------------------------------------------ 2018-05-10 17:51:27.258022 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [ready][200] freeswitch@debian-s-1vcpu-1gb-blr1-01> recv 651 bytes from udp/[124.123.68.233]:21102 at 17:51:30.077202: ------------------------------------------------------------------------ SUBSCRIBE sip:1000@159.89.163.195:5020 SIP/2.0 Via: SIP/2.0/UDP 10.144.160.39:49933;branch=z9hG4bK-524287-1---3260dc4579d5e177;rport Max-Forwards: 70 Contact: To: ;tag=fMWlF8WwfHPO From: "shashi" ;tag=835a095d Call-ID: 90726NzQ5NGNkZmEwZjJjMzg3ZmY0ZGRjYzQ1Y2RmZTI5MDU CSeq: 33 SUBSCRIBE Expires: 60 Accept: application/simple-message-summary Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: Bria Stretto release 5.2.0 stamp 90726 Event: message-summary Content-Length: 0 ------------------------------------------------------------------------ send 838 bytes to udp/[124.123.68.233]:21102 at 17:51:30.078474: ------------------------------------------------------------------------ SIP/2.0 202 Accepted Via: SIP/2.0/UDP 10.144.160.39:49933;branch=z9hG4bK-524287-1---3260dc4579d5e177;rport=21102;received=124.123.68.233 From: "shashi" ;tag=835a095d To: ;tag=fMWlF8WwfHPO Call-ID: 90726NzQ5NGNkZmEwZjJjMzg3ZmY0ZGRjYzQ1Y2RmZTI5MDU CSeq: 33 SUBSCRIBE Contact: Expires: 60 User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit 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 Subscription-State: active;expires=60 Content-Length: 0 ------------------------------------------------------------------------ send 994 bytes to udp/[124.123.68.233]:21102 at 17:51:30.186653: ------------------------------------------------------------------------ NOTIFY sip:1000@124.123.68.233:21102;rinstance=f72e49e8403a7e5f SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKa3Q091456XptD Max-Forwards: 70 From: ;tag=fMWlF8WwfHPO To: "shashi" ;tag=835a095d Call-ID: 90726NzQ5NGNkZmEwZjJjMzg3ZmY0ZGRjYzQ1Y2RmZTI5MDU CSeq: 560494501 NOTIFY Contact: User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Event: message-summary Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Subscription-State: active;expires=60 Content-Type: application/simple-message-summary Content-Length: 66 Messages-Waiting: no Message-Account: sip:1000@159.89.163.195 ------------------------------------------------------------------------ recv 430 bytes from udp/[124.123.68.233]:21102 at 17:51:30.208780: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 159.89.163.195:5020;rport=5020;branch=z9hG4bKa3Q091456XptD Contact: To: "shashi";tag=835a095d From: ;tag=fMWlF8WwfHPO Call-ID: 90726NzQ5NGNkZmEwZjJjMzg3ZmY0ZGRjYzQ1Y2RmZTI5MDU CSeq: 560494501 NOTIFY User-Agent: Bria Stretto release 5.2.0 stamp 90726 Content-Length: 0 ------------------------------------------------------------------------ **************************************Video Activation in Bria starts********************************** recv 1273 bytes from udp/[124.123.68.233]:21102 at 17:51:37.756534: ------------------------------------------------------------------------ INVITE sip:mod_sofia@159.89.163.195:5020 SIP/2.0 Via: SIP/2.0/UDP 10.144.160.39:49933;branch=z9hG4bK-524287-1---1d377b60adff825e;rport Max-Forwards: 70 Contact: To: "Extension 1003" ;tag=X0mDeFteS3ZmN From: ;tag=03fadd26 Call-ID: 9818cb57-cf1d-1236-a889-528373432f88 CSeq: 2 INVITE Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE Content-Type: application/sdp Supported: replaces User-Agent: Bria Stretto release 5.2.0 stamp 90726 Content-Length: 631 v=0 o=- 3816328869 4 IN IP4 10.144.160.39 s=Bria Stretto release 5.2.0 stamp 90726 c=IN IP4 124.123.68.233 t=0 0 m=audio 21231 RTP/AVP 102 0 8 101 9 18 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=yes a=sendrecv m=video 21234 RTP/AVP 127 126 100 a=rtpmap:127 H264/90000 a=fmtp:127 profile-level-id=428016;packetization-mode=0 a=rtpmap:126 H264/90000 a=fmtp:126 profile-level-id=428016;packetization-mode=1 a=rtpmap:100 VP8/90000 a=rtcp-fb:* nack a=rtcp-fb:* nack pli a=sendrecv ------------------------------------------------------------------------ send 444 bytes to udp/[124.123.68.233]:21102 at 17:51:37.757174: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.144.160.39:49933;branch=z9hG4bK-524287-1---1d377b60adff825e;rport=21102;received=124.123.68.233 From: ;tag=03fadd26 To: "Extension 1003" ;tag=X0mDeFteS3ZmN Call-ID: 9818cb57-cf1d-1236-a889-528373432f88 CSeq: 2 INVITE User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit Content-Length: 0 ------------------------------------------------------------------------ 2018-05-10 17:51:37.748021 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [received][100] 2018-05-10 17:51:37.748021 [DEBUG] sofia.c:7301 Remote SDP: v=0 o=- 3816328869 4 IN IP4 10.144.160.39 s=Bria Stretto release 5.2.0 stamp 90726 c=IN IP4 124.123.68.233 t=0 0 m=audio 21231 RTP/AVP 102 0 8 101 9 18 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=yes m=video 21234 RTP/AVP 127 126 100 a=rtpmap:127 H264/90000 a=fmtp:127 profile-level-id=428016;packetization-mode=0 a=rtpmap:126 H264/90000 a=fmtp:126 profile-level-id=428016;packetization-mode=1 a=rtpmap:100 VP8/90000 a=rtcp-fb:* nack a=rtcp-fb:* nack pli 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[opus:116:48000:20:0:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:5775 sofia/internal/1000@124.123.68.233:21102 Set 2833 dtmf send payload to 101 recv payload to 101 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:6058 Video Codec Compare [H264:127]/[VP8:99] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:6058 Video Codec Compare [H264:126]/[VP8:99] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:6058 Video Codec Compare [VP8:100]/[VP8:99] 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:6090 Video Codec Compare [VP8:100] +++ is saved as a match 2018-05-10 17:51:37.748021 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7 2018-05-10 17:51:37.748021 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7 2018-05-10 17:51:37.748021 [DEBUG] switch_core_media.c:3583 Set VIDEO Codec sofia/internal/1000@124.123.68.233:21102 VP8/90000 0 ms 2018-05-10 17:51:37.758014 [DEBUG] switch_core_media.c:8474 Audio params are unchanged for sofia/internal/1000@124.123.68.233:21102. 2018-05-10 17:51:37.758014 [DEBUG] switch_rtp.c:4292 Starting video timer. 2018-05-10 17:51:37.758014 [DEBUG] switch_core_media.c:9320 VIDEO RTP [sofia/internal/1000@124.123.68.233:21102] 159.89.163.195:28390->124.123.68.233:21234 codec: 100 ms: 0 [SUCCESS] 2018-05-10 17:51:37.758014 [DEBUG] switch_core_media.c:7483 sofia/internal/1000@124.123.68.233:21102 Starting Video thread 2018-05-10 17:51:37.758014 [DEBUG] switch_core_media.c:7349 sofia/internal/1000@124.123.68.233:21102 Video thread started. Echo is off 2018-05-10 17:51:37.758014 [INFO] switch_core_media.c:9400 Activating VIDEO RTCP PORT 21235 interval 1000 mux -1 2018-05-10 17:51:37.758014 [DEBUG] switch_rtp.c:4673 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 21235 2018-05-10 17:51:37.758014 [DEBUG] switch_rtp.c:2568 Setting RTCP remote addr to 124.123.68.233:21235 2 2018-05-10 17:51:37.758014 [DEBUG] sofia.c:8208 Processing updated SDP 2018-05-10 17:51:37.758014 [DEBUG] sofia_glue.c:1299 sofia/internal/1003@icc-tech.com:5020 sending invite version: 1.9.0 git a139bbd 2018-05-09 16:08:24Z 64bit Local SDP: v=0 o=FreeSWITCH 1525946413 1525946417 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 28270 RTP/AVP 102 9 0 8 103 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:103 telephone-event/48000 a=fmtp:103 0-16 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv m=video 22692 RTP/AVP 100 b=AS:1024 a=rtpmap:100 VP8/90000 a=sendrecv a=rtcp-fb:100 ccm fir a=rtcp-fb:100 ccm tmmbr a=rtcp-fb:100 nack a=rtcp-fb:100 nack pli send 1434 bytes to udp/[106.76.208.110]:49663 at 17:51:37.765655: ------------------------------------------------------------------------ INVITE sip:1003@106.76.208.110:49663;rinstance=c68d10a466e6eed9 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKBcHSBXN936cDS Max-Forwards: 70 From: ;tag=vQUmcm9avt91S To: "Brian West" ;tag=cfc94962 Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 122651284 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Session-Expires: 120;refresher=uac Min-SE: 120 Content-Type: application/sdp Content-Length: 659 X-FS-Support: update_display,send_info v=0 o=FreeSWITCH 1525946413 1525946417 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 28270 RTP/AVP 102 9 0 8 103 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:103 telephone-event/48000 a=fmtp:103 0-16 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv m=video 22692 RTP/AVP 100 b=AS:1024 a=rtpmap:100 VP8/90000 a=sendrecv a=rtcp-fb:100 ccm fir a=rtcp-fb:100 ccm tmmbr a=rtcp-fb:100 nack a=rtcp-fb:100 nack pli ------------------------------------------------------------------------ 2018-05-10 17:51:37.758014 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [calling][0] 2018-05-10 17:51:37.868032 [NOTICE] switch_vpx.c:410 VPX reset encoder picture from 320x240 to 352x288 1024 BW recv 310 bytes from udp/[106.76.208.110]:49663 at 17:51:37.981570: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 159.89.163.195:5020;rport=5020;branch=z9hG4bKBcHSBXN936cDS To: "Brian West" ;tag=cfc94962 From: ;tag=vQUmcm9avt91S Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 122651284 INVITE Content-Length: 0 ------------------------------------------------------------------------ recv 976 bytes from udp/[106.76.208.110]:49663 at 17:51:38.051765: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 159.89.163.195:5020;rport=5020;branch=z9hG4bKBcHSBXN936cDS Contact: To: "Brian West";tag=cfc94962 From: ;tag=vQUmcm9avt91S Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 122651284 INVITE Allow: INVITE, ACK, CANCEL, BYE, REFER, INFO, NOTIFY, OPTIONS, UPDATE, PRACK, MESSAGE, SUBSCRIBE Content-Type: application/sdp Supported: replaces User-Agent: Bria Stretto iOS release 5.2.4001 stamp 41079.41081 Content-Length: 385 v=0 o=- 1525974679157578 2 IN IP4 100.67.7.149 s=Cpc session c=IN IP4 100.67.7.149 t=0 0 m=audio 64218 RTP/AVP 102 0 8 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv m=video 62886 RTP/AVP 100 a=rtpmap:100 VP8/90000 a=sendrecv a=rtcp-fb:* nack a=rtcp-fb:* nack pli ------------------------------------------------------------------------ 2018-05-10 17:51:38.058042 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [completing][200] 2018-05-10 17:51:38.058042 [DEBUG] sofia.c:7301 Remote SDP: v=0 o=- 1525974679157578 2 IN IP4 100.67.7.149 s=Cpc session c=IN IP4 100.67.7.149 t=0 0 m=audio 64218 RTP/AVP 102 0 8 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv m=video 62886 RTP/AVP 100 a=rtpmap:100 VP8/90000 a=sendrecv a=rtcp-fb:* nack a=rtcp-fb:* nack pli send 370 bytes to udp/[106.76.208.110]:49663 at 17:51:38.067641: ------------------------------------------------------------------------ ACK sip:1003@106.76.208.110:49663;rinstance=c68d10a466e6eed9 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKcNajDr6c1F3Zm Max-Forwards: 70 From: ;tag=vQUmcm9avt91S To: "Brian West" ;tag=cfc94962 Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 122651284 ACK Content-Length: 0 ------------------------------------------------------------------------ 2018-05-10 17:51:38.058042 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [ready][200] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[opus:116:48000:20:0:2] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [opus:116:48000:20:0:2] ++++ is saved as a match 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:2] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:2] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:5775 sofia/internal/1003@icc-tech.com:5020 Set 2833 dtmf send payload to 101 recv payload to 101 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:6058 Video Codec Compare [VP8:100]/[VP8:99] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:6090 Video Codec Compare [VP8:100] +++ is saved as a match 2018-05-10 17:51:38.068019 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7 2018-05-10 17:51:38.068019 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:3583 Set VIDEO Codec sofia/internal/1003@icc-tech.com:5020 VP8/90000 0 ms 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:8474 Audio params are unchanged for sofia/internal/1003@icc-tech.com:5020. 2018-05-10 17:51:38.068019 [DEBUG] switch_rtp.c:4292 Starting video timer. 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:9320 VIDEO RTP [sofia/internal/1003@icc-tech.com:5020] 159.89.163.195:22692->100.67.7.149:62886 codec: 100 ms: 0 [SUCCESS] 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:7483 sofia/internal/1003@icc-tech.com:5020 Starting Video thread 2018-05-10 17:51:38.068019 [DEBUG] switch_core_media.c:7349 sofia/internal/1003@icc-tech.com:5020 Video thread started. Echo is off 2018-05-10 17:51:38.068019 [INFO] switch_core_media.c:9400 Activating VIDEO RTCP PORT 62887 interval 1000 mux -1 2018-05-10 17:51:38.068019 [DEBUG] switch_rtp.c:4673 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 62887 2018-05-10 17:51:38.068019 [DEBUG] switch_rtp.c:2568 Setting RTCP remote addr to 100.67.7.149:62887 2 send 1118 bytes to udp/[124.123.68.233]:21102 at 17:51:38.077368: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.144.160.39:49933;branch=z9hG4bK-524287-1---1d377b60adff825e;rport=21102;received=124.123.68.233 From: ;tag=03fadd26 To: "Extension 1003" ;tag=X0mDeFteS3ZmN Call-ID: 9818cb57-cf1d-1236-a889-528373432f88 CSeq: 2 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Type: application/sdp Content-Disposition: session Content-Length: 400 v=0 o=FreeSWITCH 1525954505 1525954507 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 20178 RTP/AVP 102 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 m=video 28390 RTP/AVP 100 b=AS:1024 a=rtpmap:100 VP8/90000 a=rtcp:28391 IN IP4 159.89.163.195 a=rtcp-fb:100 nack a=rtcp-fb:100 nack pli ------------------------------------------------------------------------ 2018-05-10 17:51:38.068019 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [completed][200] recv 499 bytes from udp/[124.123.68.233]:21102 at 17:51:38.122828: ------------------------------------------------------------------------ ACK sip:mod_sofia@159.89.163.195:5020 SIP/2.0 Via: SIP/2.0/UDP 10.144.160.39:49933;branch=z9hG4bK-524287-1---40d22948c6745c2a;rport Max-Forwards: 70 Contact: To: "Extension 1003" ;tag=X0mDeFteS3ZmN From: ;tag=03fadd26 Call-ID: 9818cb57-cf1d-1236-a889-528373432f88 CSeq: 2 ACK User-Agent: Bria Stretto release 5.2.0 stamp 90726 Content-Length: 0 ------------------------------------------------------------------------ 2018-05-10 17:51:38.128034 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [ready][200] 2018-05-10 17:51:38.208033 [DEBUG] switch_rtp.c:6930 Correct video RTCP ip/port confirmed. 2018-05-10 17:51:38.418034 [DEBUG] switch_rtp.c:1886 rtcp_stats_init: video ssrc[2140545607] base_seq[26864] 2018-05-10 17:51:38.468057 [DEBUG] switch_rtp.c:7490 Correct video ip/port confirmed. 2018-05-10 17:51:38.768041 [INFO] switch_rtp.c:6909 Auto Changing video RTCP port from 100.67.7.149:62887 to 106.76.208.110:62887 2018-05-10 17:51:38.768041 [DEBUG] switch_rtp.c:2568 Setting RTCP remote addr to 106.76.208.110:62887 2 recv 776 bytes from udp/[106.76.208.110]:49663 at 17:51:50.341235: ------------------------------------------------------------------------ BYE sip:1000@159.89.163.195:5020;transport=udp SIP/2.0 Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---312cdc292acf5c32;rport Max-Forwards: 70 Contact: To: ;tag=vQUmcm9avt91S From: "Brian West";tag=cfc94962 Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 3 BYE Proxy-Authorization: Digest username="1003",realm="icc-tech.com",nonce="b9660709-36c8-45de-a71c-99d8337a0f0a",uri="sip:1000@159.89.163.195:5020;transport=udp",response="34d2fa3e6eb305f33375e5c86aec7b95",cnonce="f28b91a5197ae923f3b841c671e4c385",nc=00000002,qop=auth,algorithm=MD5 User-Agent: Bria Stretto iOS release 5.2.4001 stamp 41079.41081 Content-Length: 0 ------------------------------------------------------------------------ 2018-05-10 17:51:50.338017 [NOTICE] sofia.c:1079 Hangup sofia/internal/1003@icc-tech.com:5020 [CS_EXECUTE] [NORMAL_CLEARING] send 555 bytes to udp/[106.76.208.110]:49663 at 17:51:50.347014: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 100.67.7.149:49663;branch=z9hG4bK-524287-1---312cdc292acf5c32;rport=49663;received=106.76.208.110 From: "Brian West";tag=cfc94962 To: ;tag=vQUmcm9avt91S Call-ID: ZGRiN2M4Mjk1NDI0OTIxYTQ2ODRmY2MwZTE4YTFkMDY CSeq: 3 BYE User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2018-05-10 17:51:50.338017 [DEBUG] switch_ivr_bridge.c:848 Ending video thread. 2018-05-10 17:51:50.338017 [DEBUG] switch_ivr_bridge.c:906 Ending video thread. 2018-05-10 17:51:50.338017 [DEBUG] switch_ivr_bridge.c:255 sofia/internal/1003@icc-tech.com:5020 video thread ended. 2018-05-10 17:51:50.338017 [DEBUG] switch_ivr_bridge.c:257 sofia/internal/1003@icc-tech.com:5020 skip receive message [DISPLAY] (channel is hungup already) 2018-05-10 17:51:50.348029 [DEBUG] switch_core_media.c:7450 sofia/internal/1003@icc-tech.com:5020 Video thread ended 2018-05-10 17:51:50.348029 [DEBUG] switch_ivr_bridge.c:825 sofia/internal/1003@icc-tech.com:5020 ending bridge by request from write function 2018-05-10 17:51:50.348029 [DEBUG] switch_ivr_bridge.c:848 Ending video thread. 2018-05-10 17:51:50.348029 [DEBUG] switch_ivr_bridge.c:906 Ending video thread. 2018-05-10 17:51:50.348029 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1003@icc-tech.com:5020] 2018-05-10 17:51:50.378024 [DEBUG] switch_ivr_bridge.c:255 sofia/internal/1000@124.123.68.233:21102 video thread ended. 2018-05-10 17:51:50.378024 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1000@124.123.68.233:21102] 2018-05-10 17:51:50.378024 [NOTICE] switch_ivr_bridge.c:1034 Hangup sofia/internal/1000@124.123.68.233:21102 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2018-05-10 17:51:50.378024 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1000@124.123.68.233:21102) State EXCHANGE_MEDIA going to sleep 2018-05-10 17:51:50.378024 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@124.123.68.233:21102) Running State Change CS_HANGUP (Cur 2 Tot 31) 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@124.123.68.233:21102) Callstate Change ACTIVE -> HANGUP 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@124.123.68.233:21102) State HANGUP 2018-05-10 17:51:50.388018 [DEBUG] mod_sofia.c:443 sofia/internal/1000@124.123.68.233:21102 Overriding SIP cause 480 with 200 from the other leg 2018-05-10 17:51:50.388018 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@124.123.68.233:21102 hanging up, cause: NORMAL_CLEARING 2018-05-10 17:51:50.388018 [DEBUG] mod_sofia.c:502 Sending BYE to sofia/internal/1000@124.123.68.233:21102 send 663 bytes to udp/[124.123.68.233]:21102 at 17:51:50.389368: ------------------------------------------------------------------------ BYE sip:1000@124.123.68.233:21102;rinstance=f72e49e8403a7e5f SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKDy3aFKQgyrSjg Max-Forwards: 70 From: "Extension 1003" ;tag=X0mDeFteS3ZmN To: ;tag=03fadd26 Call-ID: 9818cb57-cf1d-1236-a889-528373432f88 CSeq: 122651278 BYE User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@124.123.68.233:21102 Standard HANGUP, cause: NORMAL_CLEARING 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@124.123.68.233:21102) State HANGUP going to sleep 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@124.123.68.233:21102) State Change CS_HANGUP -> CS_REPORTING 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@124.123.68.233:21102) Running State Change CS_REPORTING (Cur 2 Tot 31) 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@124.123.68.233:21102) State REPORTING 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@124.123.68.233:21102 Standard REPORTING, cause: NORMAL_CLEARING 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@124.123.68.233:21102) State REPORTING going to sleep 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@124.123.68.233:21102) State Change CS_REPORTING -> CS_DESTROY 2018-05-10 17:51:50.388018 [DEBUG] switch_core_session.c:1713 Session 31 (sofia/internal/1000@124.123.68.233:21102) Locked, Waiting on external entities 2018-05-10 17:51:50.388018 [DEBUG] switch_ivr_bridge.c:1846 sofia/internal/1003@icc-tech.com:5020 skip receive message [TRANSFER] (channel is hungup already) 2018-05-10 17:51:50.388018 [DEBUG] switch_core_session.c:2885 sofia/internal/1003@icc-tech.com:5020 skip receive message [PHONE_EVENT] (channel is hungup already) 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1003@icc-tech.com:5020) State EXECUTE going to sleep 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@icc-tech.com:5020) Running State Change CS_HANGUP (Cur 2 Tot 31) 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1003@icc-tech.com:5020) Callstate Change ACTIVE -> HANGUP 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1003@icc-tech.com:5020) State HANGUP 2018-05-10 17:51:50.388018 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1003@icc-tech.com:5020 hanging up, cause: NORMAL_CLEARING 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1003@icc-tech.com:5020 Standard HANGUP, cause: NORMAL_CLEARING 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1003@icc-tech.com:5020) State HANGUP going to sleep 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1003@icc-tech.com:5020) State Change CS_HANGUP -> CS_REPORTING 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@icc-tech.com:5020) Running State Change CS_REPORTING (Cur 2 Tot 31) 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1003@icc-tech.com:5020) State REPORTING 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1003@icc-tech.com:5020 Standard REPORTING, cause: NORMAL_CLEARING 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1003@icc-tech.com:5020) State REPORTING going to sleep 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1003@icc-tech.com:5020) State Change CS_REPORTING -> CS_DESTROY 2018-05-10 17:51:50.388018 [DEBUG] switch_core_session.c:1713 Session 30 (sofia/internal/1003@icc-tech.com:5020) Locked, Waiting on external entities 2018-05-10 17:51:50.388018 [NOTICE] switch_core_session.c:1731 Session 30 (sofia/internal/1003@icc-tech.com:5020) Ended 2018-05-10 17:51:50.388018 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1003@icc-tech.com:5020 [CS_DESTROY] 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1003@icc-tech.com:5020) Running State Change CS_DESTROY (Cur 1 Tot 31) 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1003@icc-tech.com:5020) State DESTROY 2018-05-10 17:51:50.388018 [DEBUG] mod_sofia.c:354 sofia/internal/1003@icc-tech.com:5020 SOFIA DESTROY 2018-05-10 17:51:50.388018 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[116] PLC[0] FEC[0] 2018-05-10 17:51:50.388018 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 2018-05-10 17:51:50.388018 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 2018-05-10 17:51:50.388018 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[174] Bytes encoded[14581] Encoded length ms[3480] Average encoded bitrate bps[38882] 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1003@icc-tech.com:5020 Standard DESTROY 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1003@icc-tech.com:5020) State DESTROY going to sleep 2018-05-10 17:51:50.388018 [DEBUG] switch_core_media.c:7450 sofia/internal/1000@124.123.68.233:21102 Video thread ended 2018-05-10 17:51:50.388018 [NOTICE] switch_core_session.c:1731 Session 31 (sofia/internal/1000@124.123.68.233:21102) Ended 2018-05-10 17:51:50.388018 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1000@124.123.68.233:21102 [CS_DESTROY] 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@124.123.68.233:21102) Running State Change CS_DESTROY (Cur 0 Tot 31) 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@124.123.68.233:21102) State DESTROY 2018-05-10 17:51:50.388018 [DEBUG] mod_sofia.c:354 sofia/internal/1000@124.123.68.233:21102 SOFIA DESTROY 2018-05-10 17:51:50.388018 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 2018-05-10 17:51:50.388018 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 2018-05-10 17:51:50.388018 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] 2018-05-10 17:51:50.388018 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@124.123.68.233:21102 Standard DESTROY 2018-05-10 17:51:50.388018 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@124.123.68.233:21102) State DESTROY going to sleep recv 448 bytes from udp/[124.123.68.233]:21102 at 17:51:50.455352: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 159.89.163.195:5020;rport=5020;branch=z9hG4bKDy3aFKQgyrSjg Contact: To: ;tag=03fadd26 From: "Extension 1003" ;tag=X0mDeFteS3ZmN Call-ID: 9818cb57-cf1d-1236-a889-528373432f88 CSeq: 122651278 BYE User-Agent: Bria Stretto release 5.2.0 stamp 90726 Content-Length: 0 ------------------------------------------------------------------------ recv 651 bytes from udp/[124.123.68.233]:21102 at 17:52:24.208795: ------------------------------------------------------------------------ SUBSCRIBE sip:1000@159.89.163.195:5020 SIP/2.0 Via: SIP/2.0/UDP 10.144.160.39:49933;branch=z9hG4bK-524287-1---52bb2d32cf8c7d08;rport Max-Forwards: 70 Contact: To: ;tag=fMWlF8WwfHPO From: "shashi" ;tag=835a095d Call-ID: 90726NzQ5NGNkZmEwZjJjMzg3ZmY0ZGRjYzQ1Y2RmZTI5MDU CSeq: 34 SUBSCRIBE Expires: 60 Accept: application/simple-message-summary Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE User-Agent: Bria Stretto release 5.2.0 stamp 90726 Event: message-summary Content-Length: 0 ------------------------------------------------------------------------ send 838 bytes to udp/[124.123.68.233]:21102 at 17:52:24.209990: ------------------------------------------------------------------------ SIP/2.0 202 Accepted Via: SIP/2.0/UDP 10.144.160.39:49933;branch=z9hG4bK-524287-1---52bb2d32cf8c7d08;rport=21102;received=124.123.68.233 From: "shashi" ;tag=835a095d To: ;tag=fMWlF8WwfHPO Call-ID: 90726NzQ5NGNkZmEwZjJjMzg3ZmY0ZGRjYzQ1Y2RmZTI5MDU CSeq: 34 SUBSCRIBE Contact: Expires: 60 User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit 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 Subscription-State: active;expires=60 Content-Length: 0 ------------------------------------------------------------------------ send 994 bytes to udp/[124.123.68.233]:21102 at 17:52:24.315222: ------------------------------------------------------------------------ NOTIFY sip:1000@124.123.68.233:21102;rinstance=f72e49e8403a7e5f SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKe7v3ge8KU1F5B Max-Forwards: 70 From: ;tag=fMWlF8WwfHPO To: "shashi" ;tag=835a095d Call-ID: 90726NzQ5NGNkZmEwZjJjMzg3ZmY0ZGRjYzQ1Y2RmZTI5MDU CSeq: 560497201 NOTIFY Contact: User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20180509T160824Z~a139bbd195~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Event: message-summary Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Subscription-State: active;expires=60 Content-Type: application/simple-message-summary Content-Length: 66 Messages-Waiting: no Message-Account: sip:1000@159.89.163.195 ------------------------------------------------------------------------ recv 430 bytes from udp/[124.123.68.233]:21102 at 17:52:24.336615: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 159.89.163.195:5020;rport=5020;branch=z9hG4bKe7v3ge8KU1F5B Contact: To: "shashi";tag=835a095d From: ;tag=fMWlF8WwfHPO Call-ID: 90726NzQ5NGNkZmEwZjJjMzg3ZmY0ZGRjYzQ1Y2RmZTI5MDU CSeq: 560497201 NOTIFY User-Agent: Bria Stretto release 5.2.0 stamp 90726 Content-Length: 0 ------------------------------------------------------------------------ freeswitch@debian-s-1vcpu-1gb-blr1-01> /exit