freeswitch@bstnma-freeswitch6> reloadxml +OK [Success] 2018-03-22 10:50:00.038858 [INFO] switch_xml.c:1313 No files to include at /etc/freeswitch/dialplan/default/*.xml 2018-03-22 10:50:00.038858 [INFO] switch_xml.c:1313 No files to include at /etc/freeswitch/dialplan/public/*.xml 2018-03-22 10:50:00.119258 [INFO] switch_time.c:1423 Timezone reloaded 1750 definitions freeswitch@bstnma-freeswitch6> reloadacl +OK acl reloaded 2018-03-22 10:50:03.778858 [INFO] switch_xml.c:1313 No files to include at /etc/freeswitch/dialplan/default/*.xml 2018-03-22 10:50:03.778858 [INFO] switch_xml.c:1313 No files to include at /etc/freeswitch/dialplan/public/*.xml 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1472 Created ip list rfc6598.auto default (deny) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 100.64.0.0/10 (allow) [] to list rfc6598.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1478 Created ip list rfc1918.auto default (deny) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 10.0.0.0/8 (allow) [] to list rfc1918.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 172.16.0.0/12 (allow) [] to list rfc1918.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 192.168.0.0/16 (allow) [] to list rfc1918.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding fe80::/10 (allow) [] to list rfc1918.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1487 Created ip list wan.auto default (allow) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 0.0.0.0/8 (deny) [] to list wan.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 10.0.0.0/8 (deny) [] to list wan.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 172.16.0.0/12 (deny) [] to list wan.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 192.168.0.0/16 (deny) [] to list wan.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 169.254.0.0/16 (deny) [] to list wan.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding fe80::/10 (deny) [] to list wan.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1498 Created ip list wan_v6.auto default (allow) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 0.0.0.0/0 (deny) [] to list wan_v6.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding fe80::/10 (deny) [] to list wan_v6.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1506 Created ip list wan_v4.auto default (allow) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 0.0.0.0/8 (deny) [] to list wan_v4.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 10.0.0.0/8 (deny) [] to list wan_v4.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 172.16.0.0/12 (deny) [] to list wan_v4.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 192.168.0.0/16 (deny) [] to list wan_v4.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 169.254.0.0/16 (deny) [] to list wan_v4.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding ::/0 (deny) [] to list wan_v4.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1518 Created ip list any_v6.auto default (allow) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 0.0.0.0/0 (deny) [] to list any_v6.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1525 Created ip list any_v4.auto default (allow) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding ::/0 (deny) [] to list any_v4.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1532 Created ip list nat.auto default (deny) 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1534 Adding 216.93.246.114/255.255.255.0 (deny) to list nat.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 10.0.0.0/8 (allow) [] to list nat.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 172.16.0.0/12 (allow) [] to list nat.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 192.168.0.0/16 (allow) [] to list nat.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 100.64.0.0/10 (allow) [] to list nat.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1544 Created ip list loopback.auto default (deny) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 127.0.0.0/8 (allow) [] to list loopback.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding ::1/128 (allow) [] to list loopback.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1551 Created ip list localnet.auto default (deny) 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1554 Adding 216.93.246.114/255.255.255.0 (allow) to list localnet.auto 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1579 Created ip list stretto default (deny) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 216.93.246.0/24 (allow) [] to list stretto 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 127.0.0.1/32 (allow) [] to list stretto 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1579 Created ip list lan default (allow) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 192.0.0.0/8 (deny) [] to list lan 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 192.168.42.42/32 (allow) [] to list lan 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1579 Created ip list vancouversbc default (deny) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 69.90.51.17/32 (allow) [] to list vancouversbc 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 10.128.66.0/24 (allow) [] to list vancouversbc 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 10.128.200.0/24 (allow) [] to list vancouversbc 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 216.93.246.0/24 (allow) [] to list vancouversbc 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1579 Created ip list domains default (deny) 2018-03-22 10:50:03.868860 [INFO] switch_time.c:1423 Timezone reloaded 1750 definitions 2018-03-22 10:50:03.868860 [ERR] mod_xml_curl.c:315 Received HTTP error 404 trying to fetch http://127.0.0.1:8077/ data: [hostname=bstnma-freeswitch6§ion=directory&tag_name=domain&key_name=name&key_value=216.93.246.114&Event-Name=GENERAL&Core-UUID=737b34cf-9168-4989-bf2a-ae3f1505234d&FreeSWITCH-Hostname=bstnma-freeswitch6&FreeSWITCH-Switchname=bstnma-freeswitch6&FreeSWITCH-IPv4=216.93.246.114&FreeSWITCH-IPv6=%3A%3A1&Event-Date-Local=2018-03-22%2010%3A50%3A03&Event-Date-GMT=Thu,%2022%20Mar%202018%2014%3A50%3A03%20GMT&Event-Date-Timestamp=1521730203868860&Event-Calling-File=switch_core.c&Event-Calling-Function=switch_load_network_lists&Event-Calling-Line-Number=1604&Event-Sequence=990&domain=216.93.246.114&purpose=network-list] 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 192.0.2.0/24 (allow) [brian@216.93.246.114] to list domains 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 216.93.246.0/24 (allow) [] to list domains 2018-03-22 10:50:03.868860 [NOTICE] switch_core.c:1579 Created ip list rfc1918 default (deny) 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 10.0.0.0/8 (allow) [] to list rfc1918 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 172.16.0.0/12 (allow) [] to list rfc1918 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 192.168.0.0/16 (allow) [] to list rfc1918 2018-03-22 10:50:03.868860 [NOTICE] switch_utils.c:545 Adding 192.0.0.0/24 (allow) [] to list rfc1918 tport.c:2760 tport_wakeup_pri() tport_wakeup_pri(0x7f95dc004f40): events IN tport.c:862 tport_alloc_secondary() tport_alloc_secondary(0x7f95dc004f40): new secondary tport 0x7f95dc02e120 tport_type_tcp.c:203 tport_tcp_init_secondary() tport_tcp_init_secondary(0x7f95dc02e120): Setting TCP_KEEPIDLE to 30 tport_type_tcp.c:209 tport_tcp_init_secondary() tport_tcp_init_secondary(0x7f95dc02e120): Setting TCP_KEEPINTVL to 30 tport_type_tls.c:610 tport_tls_accept() tport_tls_accept(0x7f95dc02e120): new connection from tls/24.114.108.163:57304/sips tport_tls.c:956 tls_connect() tls_connect(0x7f95dc02e120): events NEGOTIATING tport_tls.c:956 tls_connect() tls_connect(0x7f95dc02e120): events NEGOTIATING tport_tls.c:599 tls_post_connection_check() tls_post_connection_check(0x7f95dc02e120): TLS cipher chosen (name): ECDHE-RSA-AES256-GCM-SHA384 tport_tls.c:601 tls_post_connection_check() tls_post_connection_check(0x7f95dc02e120): TLS cipher chosen (version): TLSv1/SSLv3 tport_tls.c:604 tls_post_connection_check() tls_post_connection_check(0x7f95dc02e120): TLS cipher chosen (bits/alg_bits): 256/256 tport_tls.c:607 tls_post_connection_check() tls_post_connection_check(0x7f95dc02e120): TLS cipher chosen (description): ECDHE-RSA-AES256-GCM-SHA384 TLSv1.2 Kx=ECDH Au=RSA Enc=AESGCM(256) Mac=AEAD tport_tls.c:612 tls_post_connection_check() tls_post_connection_check(0x7f95dc02e120): Peer did not provide X.509 Certificate. tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer tport.c:2784 tport_wakeup() tport_wakeup(0x7f95dc02e120): events IN tport.c:2875 tport_recv_event() tport_recv_event(0x7f95dc02e120) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f95dc02e120): tls_read() returned -1 tport_type_tls.c:338 tport_tls_set_events() tport_tls_set_events(0x7f95dc02e120): logical events IN real IN tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer tport.c:2784 tport_wakeup() tport_wakeup(0x7f95dc02e120): events IN tport.c:2875 tport_recv_event() tport_recv_event(0x7f95dc02e120) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f95dc02e120): tls_read() returned 2129 tport.c:3216 tport_recv_iovec() tport_recv_iovec(0x7f95dc02e120) msg 0x7f95dc02b8d0 from (tls/24.114.108.163:57304) has 2129 bytes, veclen = 1 recv 2129 bytes from tls/[24.114.108.163]:57304 at 10:51:24.059922: ------------------------------------------------------------------------ INVITE sip:5000@meetings6.softphone.com SIP/2.0 Via: SIP/2.0/TLS 192.0.0.4:53696;branch=z9hG4bK-524287-1---648b1a5f11a76ad9;rport Max-Forwards: 70 Contact: ;+sip.instance="" To: From: ;tag=4fddd918 Call-ID: 151911_rel67NDUwNDIwMTIzNGFiYTY0ZmNjZjc0ZDQzMzVhZTFjM2Y CSeq: 1 INVITE Allow: INVITE, ACK, CANCEL, BYE, REFER, INFO, NOTIFY, OPTIONS, UPDATE, PRACK, SUBSCRIBE, MESSAGE Content-Type: application/sdp Supported: outbound, path, replaces, 100rel User-Agent: Bria Stretto Android 5.2.2 build 103528 Content-Length: 1389 v=0 o=- 13865856205 1 IN IP4 192.0.0.4 s=Cpc session c=IN IP4 192.0.0.4 t=0 0 m=audio 53200 RTP/SAVP 120 121 18 0 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:121 SILK/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=crypto:1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA== a=crypto:2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ== a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY a=crypto:4 AES_CM_128_HMAC_SHA1_32 inline:CMT57vV8srZCT73qSK4n/b78Dz/hqRHydQzt+E/m a=sendrecv m=video 64246 RTP/SAVP 125 126 120 a=rtpmap:125 H264/90000 a=fmtp:125 profile-level-id=42801f;packetization-mode=0 a=rtpmap:126 H264/90000 a=fmtp:126 profile-level-id=42801f;packetization-mode=1 a=rtpmap:120 VP8/90000 a=rtcp-fb:* nack a=rtcp-fb:* nack pli a=crypto:1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA== a=crypto:2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ== a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY a=crypto:4 AES_CM_128_HMAC_SHA1_32 inline:CMT57vV8srZCT73qSK4n/b78Dz/hqRHydQzt+E/m a=sendrecv ------------------------------------------------------------------------ tport.c:3034 tport_deliver() tport_deliver(0x7f95dc02e120): msg 0x7f95dc02b8d0 (2129 bytes) from tls/24.114.108.163:57304/sips next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sip:5000@meetings6.softphone.com SIP/2.0 (CSeq 1) nta.c:3174 agent_check_request_via() nta: Via check: received=24.114.108.163 nta.c:3085 agent_recv_request() nta: INVITE (1) going to a default leg nta.c:1350 set_timeout() nta: timer set to 2000 ms nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering nua_stack.c:899 nh_create() nua: nh_create: entering nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7f95dc001930, 0x7f95dc001130, 0x7f95dc032d50) called soa.c:403 soa_set_params() soa_set_params(static::0x7f95dc01d8c0, ...) called nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f95dc022e20) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f95dc01d8c0) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f95dc01d8c0, (nil), 0x7f95dc02c9f4, 1389) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f95dc032d50): adding session usage tport.c:3268 tport_tsend() tport_tsend(0x7f95dc02e120) XXXXX tpn = TLS/24.114.108.163:57304 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc033cd0 133 (133) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc02c85a 77 (77) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc02c832 40 (40) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc02c8a7 82 (82) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc033d55 79 (79) tport.c:3605 tport_vsend() tport_vsend(0x7f95dc02e120): 411 bytes of 411 to tls/24.114.108.163:57304 tport.c:3503 tport_send_msg() tport_vsend returned 411 send 411 bytes to tls/[24.114.108.163]:57304 at 10:51:24.060613: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TLS 192.0.0.4:53696;branch=z9hG4bK-524287-1---648b1a5f11a76ad9;rport=57304;received=24.114.108.163 From: ;tag=4fddd918 To: Call-ID: 151911_rel67NDUwNDIwMTIzNGFiYTY0ZmNjZjc0ZDQzMzVhZTFjM2Y CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.20-37-987c9b9~64bit Content-Length: 0 ------------------------------------------------------------------------ tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (1) nua_stack.c:271 nua_stack_event() nua(0x7f95dc032d50): event i_invite 100 Trying nua_session.c:4139 signal_call_state_change() nua(0x7f95dc032d50): call state changed: init -> received, received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f95dc01d8c0, [0x7f961a8828b8], [0x7f961a8828c0], [(nil)]) called nua_stack.c:271 nua_stack_event() nua(0x7f95dc032d50): event i_state 100 Trying tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 2018-03-22 10:51:24.058843 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com [6fa735f3-f396-4893-bce4-9777442cce3b] nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2018-03-22 10:51:24.058843 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Running State Change CS_NEW (Cur 1 Tot 3) nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-03-22 10:51:24.058843 [DEBUG] sofia.c:9873 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com receiving invite from 24.114.108.163:57304 version: 1.6.20 -37-987c9b9 64bit 2018-03-22 10:51:24.058843 [DEBUG] sofia.c:10044 IP 24.114.108.163 Rejected by acl "domains". Falling back to Digest auth. nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7f95dc032d50): sent signal r_respond nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-03-22 10:51:24.058843 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State NEW nua_stack.c:573 nua_stack_signal() nua(0x7f95dc032d50): recv signal r_respond 407 Proxy Authentication Required nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f95dc01d8c0, ...) called nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f95dc01d8c0) called tport.c:3268 tport_tsend() tport_tsend(0x7f95dc02e120) XXXXX tpn = TLS/24.114.108.163:57304 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc034630 156 (156) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc02c85a 77 (77) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc0346cc 58 (58) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc02c8a7 82 (82) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc034706 552 (552) tport.c:3605 tport_vsend() tport_vsend(0x7f95dc02e120): 925 bytes of 925 to tls/24.114.108.163:57304 tport.c:3503 tport_send_msg() tport_vsend returned 925 send 925 bytes to tls/[24.114.108.163]:57304 at 10:51:24.062281: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/TLS 192.0.0.4:53696;branch=z9hG4bK-524287-1---648b1a5f11a76ad9;rport=57304;received=24.114.108.163 From: ;tag=4fddd918 To: ;tag=He77HrXQ3c8Zm Call-ID: 151911_rel67NDUwNDIwMTIzNGFiYTY0ZmNjZjc0ZDQzMzVhZTFjM2Y CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.20-37-987c9b9~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="meetings6.softphone.com", nonce="e7e3fa5c-9b45-4fad-81c4-bb254cbc70c8", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer nta.c:6791 incoming_reply() nta: sent 407 Proxy Authentication Required for INVITE (1) nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f95dc032d50): removing session usage nua_session.c:4139 signal_call_state_change() nua(0x7f95dc032d50): call state changed: received -> terminated nua_stack.c:271 nua_stack_event() nua(0x7f95dc032d50): event i_state 407 Proxy Authentication Required nua_stack.c:271 nua_stack_event() nua(0x7f95dc032d50): event i_terminated 407 Proxy Authentication Required soa.c:356 soa_destroy() soa_destroy(static::0x7f95dc01d8c0) called nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f95dc022e20) nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2018-03-22 10:51:24.058843 [DEBUG] sofia.c:2334 detaching session 6fa735f3-f396-4893-bce4-9777442cce3b nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:529 nua_signal() nua(0x7f95dc032d50): sent signal r_destroy nua_stack.c:569 nua_stack_signal() nua(0x7f95dc032d50): recv signal r_destroy nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering tport.c:2784 tport_wakeup() tport_wakeup(0x7f95dc02e120): events IN tport.c:2875 tport_recv_event() tport_recv_event(0x7f95dc02e120) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f95dc02e120): tls_read() returned 382 tport.c:3216 tport_recv_iovec() tport_recv_iovec(0x7f95dc02e120) msg 0x7f95dc034280 from (tls/24.114.108.163:57304) has 382 bytes, veclen = 1 recv 382 bytes from tls/[24.114.108.163]:57304 at 10:51:24.158805: ------------------------------------------------------------------------ ACK sip:5000@meetings6.softphone.com SIP/2.0 Via: SIP/2.0/TLS 192.0.0.4:53696;branch=z9hG4bK-524287-1---648b1a5f11a76ad9;rport Max-Forwards: 70 To: ;tag=He77HrXQ3c8Zm From: ;tag=4fddd918 Call-ID: 151911_rel67NDUwNDIwMTIzNGFiYTY0ZmNjZjc0ZDQzMzVhZTFjM2Y CSeq: 1 ACK Content-Length: 0 ------------------------------------------------------------------------ tport.c:3034 tport_deliver() tport_deliver(0x7f95dc02e120): msg 0x7f95dc034280 (382 bytes) from tls/24.114.108.163:57304/sips next=(nil) nta.c:2880 agent_recv_request() nta: received ACK sip:5000@meetings6.softphone.com SIP/2.0 (CSeq 1) nta.c:3174 agent_check_request_via() nta: Via check: received=24.114.108.163 nta.c:3019 agent_recv_request() nta: ACK (1) is going to INVITE (1) tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer tport.c:2784 tport_wakeup() tport_wakeup(0x7f95dc02e120): events IN tport.c:2875 tport_recv_event() tport_recv_event(0x7f95dc02e120) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f95dc02e120): tls_read() returned -1 tport_type_tls.c:338 tport_tls_set_events() tport_tls_set_events(0x7f95dc02e120): logical events IN real IN tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer tport.c:2784 tport_wakeup() tport_wakeup(0x7f95dc02e120): events IN tport.c:2875 tport_recv_event() tport_recv_event(0x7f95dc02e120) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f95dc02e120): tls_read() returned 2433 tport.c:3216 tport_recv_iovec() tport_recv_iovec(0x7f95dc02e120) msg 0x7f95dc034280 from (tls/24.114.108.163:57304) has 2433 bytes, veclen = 1 recv 2433 bytes from tls/[24.114.108.163]:57304 at 10:51:24.240914: ------------------------------------------------------------------------ INVITE sip:5000@meetings6.softphone.com SIP/2.0 Via: SIP/2.0/TLS 192.0.0.4:53696;branch=z9hG4bK-524287-1---b65f79db56feac6e;rport Max-Forwards: 70 Contact: ;+sip.instance="" To: From: ;tag=4fddd918 Call-ID: 151911_rel67NDUwNDIwMTIzNGFiYTY0ZmNjZjc0ZDQzMzVhZTFjM2Y CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, BYE, REFER, INFO, NOTIFY, OPTIONS, UPDATE, PRACK, SUBSCRIBE, MESSAGE Content-Type: application/sdp Proxy-Authorization: Digest username="guest_JamieStracha_3486d97",realm="meetings6.softphone.com",nonce="e7e3fa5c-9b45-4fad-81c4-bb254cbc70c8",uri="sip:5000@meetings6.softphone.com",response="f3e8f35bda60c1e2a5180854bd4f863c",cnonce="b52d75b8e318813db90d219296b1719e",nc=00000001,qop=auth,algorithm=MD5 Supported: outbound, path, replaces, 100rel User-Agent: Bria Stretto Android 5.2.2 build 103528 Content-Length: 1389 v=0 o=- 13865856205 1 IN IP4 192.0.0.4 s=Cpc session c=IN IP4 192.0.0.4 t=0 0 m=audio 53200 RTP/SAVP 120 121 18 0 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:121 SILK/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=crypto:1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA== a=crypto:2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ== a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY a=crypto:4 AES_CM_128_HMAC_SHA1_32 inline:CMT57vV8srZCT73qSK4n/b78Dz/hqRHydQzt+E/m a=sendrecv m=video 64246 RTP/SAVP 125 126 120 a=rtpmap:125 H264/90000 a=fmtp:125 profile-level-id=42801f;packetization-mode=0 a=rtpmap:126 H264/90000 a=fmtp:126 profile-level-id=42801f;packetization-mode=1 a=rtpmap:120 VP8/90000 a=rtcp-fb:* nack a=rtcp-fb:* nack pli a=crypto:1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA== a=crypto:2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ== a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY a=crypto:4 AES_CM_128_HMAC_SHA1_32 inline:CMT57vV8srZCT73qSK4n/b78Dz/hqRHydQzt+E/m a=sendrecv ------------------------------------------------------------------------ tport.c:3034 tport_deliver() tport_deliver(0x7f95dc02e120): msg 0x7f95dc034280 (2433 bytes) from tls/24.114.108.163:57304/sips next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sip:5000@meetings6.softphone.com SIP/2.0 (CSeq 2) nta.c:3174 agent_check_request_via() nta: Via check: received=24.114.108.163 nta.c:3085 agent_recv_request() nta: INVITE (2) going to a default leg nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering nua_stack.c:899 nh_create() nua: nh_create: entering nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7f95dc001930, 0x7f95dc001130, 0x7f95dc021300) called soa.c:403 soa_set_params() soa_set_params(static::0x7f95dc0216b0, ...) called nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f95dc022e80) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f95dc0216b0) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f95dc0216b0, (nil), 0x7f95dc033a74, 1389) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f95dc021300): adding session usage tport.c:3268 tport_tsend() tport_tsend(0x7f95dc02e120) XXXXX tpn = TLS/24.114.108.163:57304 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc036320 133 (133) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc0337aa 77 (77) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc033782 40 (40) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc0337f7 82 (82) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc0363a5 79 (79) tport.c:3605 tport_vsend() tport_vsend(0x7f95dc02e120): 411 bytes of 411 to tls/24.114.108.163:57304 tport.c:3503 tport_send_msg() tport_vsend returned 411 send 411 bytes to tls/[24.114.108.163]:57304 at 10:51:24.241459: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TLS 192.0.0.4:53696;branch=z9hG4bK-524287-1---b65f79db56feac6e;rport=57304;received=24.114.108.163 From: ;tag=4fddd918 To: Call-ID: 151911_rel67NDUwNDIwMTIzNGFiYTY0ZmNjZjc0ZDQzMzVhZTFjM2Y CSeq: 2 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.20-37-987c9b9~64bit Content-Length: 0 ------------------------------------------------------------------------ tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (2) nua_stack.c:271 nua_stack_event() nua(0x7f95dc021300): event i_invite 100 Trying nua_session.c:4139 signal_call_state_change() nua(0x7f95dc021300): call state changed: init -> received, received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f95dc0216b0, [0x7f961a8828b8], [0x7f961a8828c0], [(nil)]) called nua_stack.c:271 nua_stack_event() nua(0x7f95dc021300): event i_state 100 Trying tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 2018-03-22 10:51:24.238876 [DEBUG] sofia.c:2442 Re-attaching to session 6fa735f3-f396-4893-bce4-9777442cce3b nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-03-22 10:51:24.238876 [DEBUG] sofia.c:9873 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com receiving invite from 24.114.108.163:57304 version: 1.6.20 -37-987c9b9 64bit 2018-03-22 10:51:24.238876 [DEBUG] sofia.c:10044 IP 24.114.108.163 Rejected by acl "domains". Falling back to Digest auth. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-03-22 10:51:24.248861 [DEBUG] sofia.c:7084 Channel sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com entering state [received][100] 2018-03-22 10:51:24.248861 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=- 13865856205 1 IN IP4 192.0.0.4 s=Cpc session c=IN IP4 192.0.0.4 t=0 0 m=audio 53200 RTP/SAVP 120 121 18 0 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:121 SILK/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=crypto:1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA== a=crypto:2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ== a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY a=crypto:4 AES_CM_128_HMAC_SHA1_32 inline:CMT57vV8srZCT73qSK4n/b78Dz/hqRHydQzt+E/m m=video 64246 RTP/SAVP 125 126 120 a=rtpmap:125 H264/90000 a=fmtp:125 profile-level-id=42801f;packetization-mode=0 a=rtpmap:126 H264/90000 a=fmtp:126 profile-level-id=42801f;packetization-mode=1 a=rtpmap:120 VP8/90000 a=rtcp-fb:* nack a=rtcp-fb:* nack pli a=crypto:1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA== a=crypto:2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ== a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY a=crypto:4 AES_CM_128_HMAC_SHA1_32 inline:CMT57vV8srZCT73qSK4n/b78Dz/hqRHydQzt+E/m 2018-03-22 10:51:24.248861 [DEBUG] sofia.c:7486 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State Change CS_NEW -> CS_INIT nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Running State Change CS_INIT (Cur 1 Tot 3) 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State INIT 2018-03-22 10:51:24.248861 [DEBUG] mod_sofia.c:90 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com SOFIA INIT 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:40 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Standard INIT 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State Change CS_INIT -> CS_ROUTING 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State INIT going to sleep 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Running State Change CS_ROUTING (Cur 1 Tot 3) 2018-03-22 10:51:24.248861 [DEBUG] switch_channel.c:2249 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Callstate Change DOWN -> RINGING 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State ROUTING 2018-03-22 10:51:24.248861 [DEBUG] mod_sofia.c:143 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com SOFIA ROUTING 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:236 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Standard ROUTING 2018-03-22 10:51:24.248861 [INFO] mod_dialplan_xml.c:637 Processing guest_JamieStracha_3486d97 ->5000 in context public Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com parsing [public->unloop] continue=false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com parsing [public->outside_call] continue=true Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Absolute Condition [outside_call] Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Action set(outside_call=true) Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com parsing [public->call_debug] continue=true Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com parsing [public->public_extensions] continue=false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (PASS) [public_extensions] destination_number(5000) =~ /^(5000)$/ break=on-false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Action transfer(5000 XML default) 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State Change CS_ROUTING -> CS_EXECUTE 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State ROUTING going to sleep 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Running State Change CS_EXECUTE (Cur 1 Tot 3) 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State EXECUTE 2018-03-22 10:51:24.248861 [DEBUG] mod_sofia.c:198 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com SOFIA EXECUTE 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:328 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Standard EXECUTE EXECUTE sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com set(outside_call=true) 2018-03-22 10:51:24.248861 [DEBUG] mod_dptools.c:1548 SET sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com [outside_call]=[true] EXECUTE sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com export(RFC2822_DATE=Thu, 22 Mar 2018 10:51:24 -0400) 2018-03-22 10:51:24.248861 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 22 Mar 2018 10:51:24 -0400] EXECUTE sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com transfer(5000 XML default) 2018-03-22 10:51:24.248861 [DEBUG] switch_ivr.c:2165 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State Change CS_EXECUTE -> CS_ROUTING 2018-03-22 10:51:24.248861 [NOTICE] switch_ivr.c:2172 Transfer sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com to XML[5000@default] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State EXECUTE going to sleep 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Running State Change CS_ROUTING (Cur 1 Tot 3) 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State ROUTING 2018-03-22 10:51:24.248861 [DEBUG] mod_sofia.c:143 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com SOFIA ROUTING 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:236 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Standard ROUTING 2018-03-22 10:51:24.248861 [INFO] mod_dialplan_xml.c:637 Processing guest_JamieStracha_3486d97 ->5000 in context default Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com parsing [default->unloop] continue=false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com parsing [default->conference_lobby] continue=false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (PASS) [conference_lobby] destination_number(5000) =~ /^(5000(?:#\d{4})?)$/ break=on-false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Action answer() Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Action park() 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State Change CS_ROUTING -> CS_EXECUTE 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State ROUTING going to sleep 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Running State Change CS_EXECUTE (Cur 1 Tot 3) 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State EXECUTE 2018-03-22 10:51:24.248861 [DEBUG] mod_sofia.c:198 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com SOFIA EXECUTE 2018-03-22 10:51:24.248861 [DEBUG] switch_core_state_machine.c:328 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Standard EXECUTE EXECUTE sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com answer() 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_256_GCM_8] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_128_GCM_8] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_256_HMAC_SHA1_80] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_192_HMAC_SHA1_80] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_HMAC_SHA1_80] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_256_HMAC_SHA1_32] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_192_HMAC_SHA1_32] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_HMAC_SHA1_32] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_NULL_AUTH] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1460 Unsupported Crypto [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_256_GCM_8] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_128_GCM_8] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_256_HMAC_SHA1_80] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_192_HMAC_SHA1_80] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_HMAC_SHA1_80] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_256_HMAC_SHA1_32] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_192_HMAC_SHA1_32] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_HMAC_SHA1_32] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_NULL_AUTH] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1460 Unsupported Crypto [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_256_GCM_8] in [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_128_GCM_8] in [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_256_HMAC_SHA1_80] in [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_192_HMAC_SHA1_80] in [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_HMAC_SHA1_80] in [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1400 Found suite AES_CM_128_HMAC_SHA1_80 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1466 Set Remote Key [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1128 Set Local audio crypto Key [3 AES_CM_128_HMAC_SHA1_80 inline:Xb2QITxAoJtCfiEtdLY5Y98JUJjOGk76EpSr0CVC] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:1]/[opus:116:48000:20:0:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [SILK:121:8000:20:0:1]/[opus:116:48000:20:0:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [SILK:121:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [SILK:121:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000 2018-03-22 10:51:24.248861 [DEBUG] mod_opus.c:598 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [64000bps] 2018-03-22 10:51:24.248861 [DEBUG] mod_opus.c:598 Opus encoder: set bitrate based on maxaveragebitrate value found in SDP or local config [64000bps] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com opus/48000 20 ms 960 samples 0 bits 1 channels 2018-03-22 10:51:24.248861 [DEBUG] switch_core_codec.c:111 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Original read codec set to opus:116 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4767 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Set 2833 dtmf send payload to 101 recv payload to 101 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_256_GCM_8] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_128_GCM_8] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_256_HMAC_SHA1_80] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_192_HMAC_SHA1_80] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_HMAC_SHA1_80] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_256_HMAC_SHA1_32] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_192_HMAC_SHA1_32] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_HMAC_SHA1_32] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_NULL_AUTH] in [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1460 Unsupported Crypto [1 AES_256_CM_HMAC_SHA1_80 inline:jQfU0+5pc+3H0wdHC2SO3tjqbY0otX2ARGJTykCisrPveQLm3WtocnCzJYA3HA==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_256_GCM_8] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_128_GCM_8] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_256_HMAC_SHA1_80] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_192_HMAC_SHA1_80] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_HMAC_SHA1_80] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_256_HMAC_SHA1_32] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_192_HMAC_SHA1_32] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_HMAC_SHA1_32] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_NULL_AUTH] in [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1460 Unsupported Crypto [2 AES_256_CM_HMAC_SHA1_32 inline:nRN9B+uJ35YmMNAW4bEmSqX+W9akezqeBZv0puRz4qmAVrkBoPC46oa25WMHtQ==] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_256_GCM_8] in [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AEAD_AES_128_GCM_8] in [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_256_HMAC_SHA1_80] in [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_192_HMAC_SHA1_80] in [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1395 looking for crypto suite [AES_CM_128_HMAC_SHA1_80] in [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1400 Found suite AES_CM_128_HMAC_SHA1_80 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1466 Set Remote Key [3 AES_CM_128_HMAC_SHA1_80 inline:/oCnYp9d/G2zAjauf/wM4elvNHr/aHznoCJMmPcY] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:1128 Set Local video crypto Key [3 AES_CM_128_HMAC_SHA1_80 inline:YtUdphzRH+ykAwQOsX7UQ+K+OHzjXE0Ti6pnAAKs] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4950 Video Codec Compare [H264:125]/[H264:99] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4982 Video Codec Compare [H264:125] +++ is saved as a match 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4950 Video Codec Compare [H264:126]/[H264:99] 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4982 Video Codec Compare [H264:126] +++ is saved as a match 2018-03-22 10:51:24.248861 [DEBUG] switch_core_media.c:4950 Video Codec Compare [VP8:120]/[H264:99] 2018-03-22 10:51:24.248861 [NOTICE] avcodec.c:1022 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10 2018-03-22 10:51:24.258855 [NOTICE] avcodec.c:1022 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10 2018-03-22 10:51:24.258855 [DEBUG] switch_core_media.c:2871 Set VIDEO Codec sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com H264/90000 0 ms 2018-03-22 10:51:24.258855 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com] 216.93.246.114 port 31714 -> 192.0.0.4 port 53200 codec: 120 ms: 20 2018-03-22 10:51:24.258855 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 960 bytes per 20ms 2018-03-22 10:51:24.258855 [DEBUG] switch_core_media.c:7096 Activating RTCP PORT 53201 2018-03-22 10:51:24.258855 [DEBUG] switch_rtp.c:4533 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 53201 2018-03-22 10:51:24.258855 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 192.0.0.4:53201 2 2018-03-22 10:51:24.258855 [DEBUG] switch_core_media.c:7180 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Set 2833 dtmf send payload to 101 2018-03-22 10:51:24.258855 [DEBUG] switch_core_media.c:7187 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Set 2833 dtmf receive payload to 101 2018-03-22 10:51:24.258855 [DEBUG] switch_core_media.c:7210 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Set rtp dtmf delay to 40 2018-03-22 10:51:24.258855 [INFO] switch_rtp.c:3941 Activating audio Secure RTP SEND 2018-03-22 10:51:24.258855 [INFO] switch_rtp.c:3919 Activating audio Secure RTP RECV 2018-03-22 10:51:24.258855 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80 2018-03-22 10:51:24.258855 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80 2018-03-22 10:51:24.258855 [DEBUG] switch_rtp.c:4152 Starting video timer. 2018-03-22 10:51:24.258855 [DEBUG] switch_core_media.c:7399 VIDEO RTP [sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com] 216.93.246.114:18614->192.0.0.4:64246 codec: 125 ms: 0 [SUCCESS] 2018-03-22 10:51:24.258855 [DEBUG] switch_core_media.c:6003 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Starting Video thread 2018-03-22 10:51:24.258855 [DEBUG] switch_core_media.c:5869 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Video thread started. Echo is off 2018-03-22 10:51:24.258855 [INFO] switch_core_media.c:7479 Activating VIDEO RTCP PORT 64247 interval 1000 mux -1 2018-03-22 10:51:24.258855 [DEBUG] switch_rtp.c:4533 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 64247 2018-03-22 10:51:24.258855 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 192.0.0.4:64247 2 2018-03-22 10:51:24.258855 [INFO] switch_rtp.c:3941 Activating video Secure RTP SEND 2018-03-22 10:51:24.258855 [INFO] switch_rtp.c:3919 Activating video Secure RTP RECV 2018-03-22 10:51:24.258855 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80 2018-03-22 10:51:24.258855 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com! 2018-03-22 10:51:24.258855 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80 2018-03-22 10:51:24.258855 [DEBUG] switch_channel.c:3474 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Callstate Change RINGING -> EARLY 2018-03-22 10:51:24.258855 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com. 2018-03-22 10:51:24.258855 [DEBUG] switch_core_media.c:7257 Video params are unchanged for sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com. 2018-03-22 10:51:24.258855 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com: v=0 o=FreeSWITCH 1521698570 1521698571 IN IP4 216.93.246.114 s=FreeSWITCH c=IN IP4 216.93.246.114 t=0 0 m=audio 31714 RTP/SAVP 120 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv a=rtcp:31715 IN IP4 216.93.246.114 a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:Xb2QITxAoJtCfiEtdLY5Y98JUJjOGk76EpSr0CVC m=video 18614 RTP/SAVP 125 b=AS:2048 a=rtpmap:125 H264/90000 a=fmtp:125 profile-level-id=42801f;packetization-mode=0 a=rtcp:18615 IN IP4 216.93.246.114 a=rtcp-fb:125 nack a=rtcp-fb:125 nack pli a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:YtUdphzRH+ykAwQOsX7UQ+K+OHzjXE0Ti6pnAAKs m=video 18614 RTP/SAVP 125 b=AS:2048 a=rtpmap:125 H264/90000 a=fmtp:125 profile-level-id=42801f;packetization-mode=0 a=rtcp:18615 IN IP4 216.93.246.114 a=rtcp-fb:125 nack a=rtcp-fb:125 nack pli nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7f95dc021300): sent signal r_respond nua_stack.c:573 nua_stack_signal() nua(0x7f95dc021300): recv signal r_respond 200 OK nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f95dc0216b0, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f95dc0216b0, (nil), 0x7f9560011bdd, -1) called soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f95dc0216b0, (nil), 0x7f9560011bdd, -1) called 2018-03-22 10:51:24.268777 [NOTICE] mod_dptools.c:1312 Channel [sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com] has been answered nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x7f95dc0216b0) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f95dc0216b0, soa_generate_answer): called soa_static.c:1189 offer_answer_step() soa_static(0x7f95dc0216b0, soa_generate_answer): generating local description soa_static.c:1230 offer_answer_step() soa_static(0x7f95dc0216b0, soa_generate_answer): upgrade with remote description soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f961a880b00, 0x7f95dc036d20, ""): called soa_static.c:1446 offer_answer_step() soa_static(0x7f95dc0216b0, soa_generate_answer): storing local description soa.c:1730 soa_activate() soa_activate(static::0x7f95dc0216b0, (nil)) called soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f95dc0216b0, [(nil)], [0x7f961a882c38], [0x7f961a882c34]) called tport.c:3268 tport_tsend() tport_tsend(0x7f95dc02e120) XXXXX tpn = TLS/24.114.108.163:57304 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc039b10 129 (129) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc0337aa 77 (77) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc039b91 58 (58) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc0337f7 82 (82) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc039bcb 633 (633) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f95dc034b10 0x7f95dc03e270 699 (699) tport.c:3605 tport_vsend() tport_vsend(0x7f95dc02e120): 1678 bytes of 1678 to tls/24.114.108.163:57304 tport.c:3503 tport_send_msg() tport_vsend returned 1678 send 1678 bytes to tls/[24.114.108.163]:57304 at 10:51:24.269152: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 192.0.0.4:53696;branch=z9hG4bK-524287-1---b65f79db56feac6e;rport=57304;received=24.114.108.163 From: ;tag=4fddd918 To: ;tag=jQ00KKeU0Nyjg Call-ID: 151911_rel67NDUwNDIwMTIzNGFiYTY0ZmNjZjc0ZDQzMzVhZTFjM2Y CSeq: 2 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.20-37-987c9b9~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: 699 Remote-Party-ID: "5000" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1521698570 1521698571 IN IP4 216.93.246.114 s=FreeSWITCH c=IN IP4 216.93.246.114 t=0 0 m=audio 31714 RTP/SAVP 120 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=rtcp:31715 IN IP4 216.93.246.114 a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:Xb2QITxAoJtCfiEtdLY5Y98JUJjOGk76EpSr0CVC m=video 18614 RTP/SAVP 125 b=AS:2048 a=rtpmap:125 H264/90000 a=fmtp:125 profile-level-id=42801f;packetization-mode=0 a=rtcp:18615 IN IP4 216.93.246.114 a=rtcp-fb:125 nack a=rtcp-fb:125 nack pli a=crypto:3 AES_CM_128_HMAC_SHA1_80 inline:YtUdphzRH+ykAwQOsX7UQ+K+OHzjXE0Ti6pnAAKs ------------------------------------------------------------------------ tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (2) nta.c:1348 set_timeout() nta: timer shortened to 500 ms nua_session.c:4139 signal_call_state_change() nua(0x7f95dc021300): call state changed: received -> completed, sent answer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f95dc0216b0, [0x7f961a882ce8], [0x7f961a882cf0], [(nil)]) called soa.c:616 soa_get_params() soa_get_params(static::0x7f95dc0216b0, ...) called nua_stack.c:271 nua_stack_event() nua(0x7f95dc021300): event i_state 200 OK nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2018-03-22 10:51:24.268777 [DEBUG] switch_channel.c:3773 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Callstate Change EARLY -> ACTIVE nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-03-22 10:51:24.268777 [DEBUG] sofia.c:7084 Channel sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com entering state [completed][200] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering EXECUTE sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com park() 2018-03-22 10:51:24.268777 [DEBUG] switch_ivr.c:980 Codec Activated L16@48000hz 1 channels 20ms 2018-03-22 10:51:24.288800 [DEBUG] switch_ivr.c:2165 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State Change CS_EXECUTE -> CS_ROUTING 2018-03-22 10:51:24.288800 [NOTICE] switch_ivr.c:2172 Transfer sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com to XML[bridge-1010-collab-1080@default] 2018-03-22 10:51:24.298837 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State EXECUTE going to sleep 2018-03-22 10:51:24.298837 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Running State Change CS_ROUTING (Cur 1 Tot 3) 2018-03-22 10:51:24.298837 [DEBUG] switch_channel.c:2249 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Callstate Change ACTIVE -> RINGING 2018-03-22 10:51:24.298837 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State ROUTING 2018-03-22 10:51:24.298837 [DEBUG] mod_sofia.c:143 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com SOFIA ROUTING 2018-03-22 10:51:24.298837 [DEBUG] switch_core_state_machine.c:236 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Standard ROUTING 2018-03-22 10:51:24.298837 [INFO] mod_dialplan_xml.c:637 Processing guest_JamieStracha_3486d97 ->bridge-1010-collab-1080 in context default Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com parsing [default->unloop] continue=false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com parsing [default->conference_lobby] continue=false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (FAIL) [conference_lobby] destination_number(bridge-1010-collab-1080) =~ /^(5000(?:#\d{4})?)$/ break=on-false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com parsing [default->lobby_transfer] continue=false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (FAIL) [lobby_transfer] destination_number(bridge-1010-collab-1080) =~ /^xfer-(.*)$/ break=on-false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com parsing [default->stretto_conference_physical_bridge] continue=false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Regex (PASS) [stretto_conference_physical_bridge] destination_number(bridge-1010-collab-1080) =~ /^(bridge-\d{4})-(.*)?$/ break=on-false Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Action answer() Dialplan: sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Action conference(bridge-1010@collab-1080) 2018-03-22 10:51:24.298837 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State Change CS_ROUTING -> CS_EXECUTE 2018-03-22 10:51:24.298837 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State ROUTING going to sleep 2018-03-22 10:51:24.298837 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Running State Change CS_EXECUTE (Cur 1 Tot 3) 2018-03-22 10:51:24.298837 [DEBUG] switch_channel.c:2251 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Callstate Change RINGING -> ACTIVE 2018-03-22 10:51:24.298837 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State EXECUTE 2018-03-22 10:51:24.298837 [DEBUG] mod_sofia.c:198 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com SOFIA EXECUTE 2018-03-22 10:51:24.298837 [DEBUG] switch_core_state_machine.c:328 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Standard EXECUTE EXECUTE sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com answer() EXECUTE sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com conference(bridge-1010@collab-1080) 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:275 Adding layout group ribbon 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon1 to layout group ribbon 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon2 to layout group ribbon 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon3 to layout group ribbon 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon4 to layout group ribbon 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon5 to layout group ribbon 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon6 to layout group ribbon 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:275 Adding layout group focus 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up_top_left+5 to layout group focus 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up_top_left+7 to layout group focus 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up_top_left+9 to layout group focus 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:275 Adding layout group grid 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1x1 to layout group grid 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 2x1 to layout group grid 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1x1+2x1 to layout group grid 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 2x2 to layout group grid 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 3x3 to layout group grid 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 4x4 to layout group grid 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 5x5 to layout group grid 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 6x6 to layout group grid 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 8x8 to layout group grid 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:275 Adding layout group townhall 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1x1 to layout group townhall 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:275 Adding layout group 1up-ribbon-progression 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon1 to layout group 1up-ribbon-progression 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon2 to layout group 1up-ribbon-progression 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon3 to layout group 1up-ribbon-progression 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon4 to layout group 1up-ribbon-progression 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon5 to layout group 1up-ribbon-progression 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up-ribbon6 to layout group 1up-ribbon-progression 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:275 Adding layout group grid-zoom 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1x1 to layout group grid-zoom 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 2x1-zoom to layout group grid-zoom 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 3x1-zoom to layout group grid-zoom 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 2x2 to layout group grid-zoom 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 5-grid-zoom to layout group grid-zoom 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 3x2-zoom to layout group grid-zoom 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 7-grid-zoom to layout group grid-zoom 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 4x2-zoom to layout group grid-zoom 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 3x3 to layout group grid-zoom 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:275 Adding layout group 1up_top_left_plus 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up_top_left+5 to layout group 1up_top_left_plus 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up_top_left+7 to layout group 1up_top_left_plus 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 1up_top_left+9 to layout group 1up_top_left_plus 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:275 Adding layout group 3up_plus 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 3up+4 to layout group 3up_plus 2018-03-22 10:51:24.298837 [DEBUG] conference_video.c:284 Adding node 3up+9 to layout group 3up_plus 2018-03-22 10:51:24.298837 [DEBUG] mod_conference.c:3084 using channel sound prefix: /usr/share/freeswitch/sounds/en/us/callie 2018-03-22 10:51:24.308822 [DEBUG] conference_video.c:1166 Canvas position 1 applied layout 1up_top_left+5 2018-03-22 10:51:24.308822 [DEBUG] conference_video.c:1256 Layout set to 1up_top_left+5 2018-03-22 10:51:24.308822 [DEBUG] conference_video.c:1216 Canvas attached to position 0 2018-03-22 10:51:24.308822 [DEBUG] conference_member.c:1693 Raw Codec Activation Success L16@48000hz 1 channel 20ms 2018-03-22 10:51:24.308822 [DEBUG] conference_member.c:1740 Raw Codec Activation Success L16@48000hz 2 channel 20ms 2018-03-22 10:51:24.308822 [DEBUG] mod_conference.c:220 Setup timer success interval: 20 samples: 960 2018-03-22 10:51:24.308822 [DEBUG] switch_core_codec.c:223 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Push codec L16:100 2018-03-22 10:51:24.368833 [DEBUG] conference_member.c:128 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com binding '0' to 'mute' 2018-03-22 10:51:24.368833 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf' 2018-03-22 10:51:24.368833 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f96195a2dd0 data: 0x7f9560855d70 2018-03-22 10:51:24.368833 [DEBUG] conference_member.c:128 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com binding '*' to 'deaf mute' 2018-03-22 10:51:24.368833 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding */conf/0 callback: 0x7f96195a2dd0 data: 0x7f9560855da0 2018-03-22 10:51:24.368833 [DEBUG] conference_member.c:128 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com binding '9' to 'energy up' 2018-03-22 10:51:24.368833 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f96195a2dd0 data: 0x7f9560855dd0 2018-03-22 10:51:24.368833 [DEBUG] conference_member.c:128 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com binding '8' to 'energy equ' 2018-03-22 10:51:24.368833 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f96195a2dd0 data: 0x7f9560855e00 2018-03-22 10:51:24.368833 [DEBUG] conference_member.c:128 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com binding '7' to 'energy dn' 2018-03-22 10:51:24.368833 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f96195a2dd0 data: 0x7f9560855e30 2018-03-22 10:51:24.368833 [DEBUG] conference_member.c:128 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com binding '3' to 'vol talk up' 2018-03-22 10:51:24.368833 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f96195a2dd0 data: 0x7f9560855e60 2018-03-22 10:51:24.368833 [DEBUG] conference_member.c:128 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com binding '2' to 'vol talk zero' 2018-03-22 10:51:24.368833 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f96195a2dd0 data: 0x7f9560899f28 2018-03-22 10:51:24.368833 [DEBUG] conference_member.c:128 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com binding '1' to 'vol talk dn' 2018-03-22 10:51:24.368833 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f96195a2dd0 data: 0x7f9560899f58 2018-03-22 10:51:24.368833 [DEBUG] conference_member.c:128 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com binding '6' to 'vol listen up' 2018-03-22 10:51:24.368833 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f96195a2dd0 data: 0x7f9560899f88 2018-03-22 10:51:24.368833 [DEBUG] conference_member.c:128 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com binding '5' to 'vol listen zero' 2018-03-22 10:51:24.368833 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f96195a2dd0 data: 0x7f9560899fb8 2018-03-22 10:51:24.368833 [DEBUG] conference_member.c:128 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com binding '4' to 'vol listen dn' 2018-03-22 10:51:24.368833 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f96195a2dd0 data: 0x7f9560899fe8 2018-03-22 10:51:24.368833 [DEBUG] switch_core_file.c:342 File /stretto/current/mediaprompts/MEDIA/crickets.wav sample rate 8000 doesn't match requested rate 48000 2018-03-22 10:51:24.378778 [WARNING] switch_core_file.c:360 File has 1 channels, muxing to 2 channels will occur. 2018-03-22 10:51:24.378778 [DEBUG] conference_loop.c:1142 Setup timer soft success interval: 20 samples: 960 from codec opus 2018-03-22 10:51:24.378778 [INFO] avcodec.c:1083 initializing encoder 352x288 2018-03-22 10:51:24.378778 [DEBUG] avcodec.c:832 NVENC HW CODEC NOT PRESENT using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 profile Constrained Baseline, level 3.1 tport.c:2784 tport_wakeup() tport_wakeup(0x7f95dc02e120): events IN tport.c:2875 tport_recv_event() tport_recv_event(0x7f95dc02e120) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f95dc02e120): tls_read() returned 585 tport.c:3216 tport_recv_iovec() tport_recv_iovec(0x7f95dc02e120) msg 0x7f95dc035c80 from (tls/24.114.108.163:57304) has 585 bytes, veclen = 1 recv 585 bytes from tls/[24.114.108.163]:57304 at 10:51:24.414698: ------------------------------------------------------------------------ ACK sip:5000@216.93.246.114:5061;transport=tls SIP/2.0 Via: SIP/2.0/TLS 192.0.0.4:53696;branch=z9hG4bK-524287-1---c9ea5506370346c0;rport Max-Forwards: 70 Contact: ;+sip.instance="" To: ;tag=jQ00KKeU0Nyjg From: ;tag=4fddd918 Call-ID: 151911_rel67NDUwNDIwMTIzNGFiYTY0ZmNjZjc0ZDQzMzVhZTFjM2Y CSeq: 2 ACK User-Agent: Bria Stretto Android 5.2.2 build 103528 Content-Length: 0 ------------------------------------------------------------------------ tport.c:3034 tport_deliver() tport_deliver(0x7f95dc02e120): msg 0x7f95dc035c80 (585 bytes) from tls/24.114.108.163:57304/sips next=(nil) nta.c:2880 agent_recv_request() nta: received ACK sip:5000@216.93.246.114:5061;transport=tls SIP/2.0 (CSeq 2) nta.c:3174 agent_check_request_via() nta: Via check: received=24.114.108.163 nta.c:3019 agent_recv_request() nta: ACK (2) is going to INVITE (2) nua_session.c:2569 process_ack_or_cancel() nua: process_ack_or_cancel: entering soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f95dc0216b0) called nua_stack.c:271 nua_stack_event() nua(0x7f95dc021300): event i_ack 200 OK nua_session.c:4139 signal_call_state_change() nua(0x7f95dc021300): call state changed: completed -> ready nua_stack.c:271 nua_stack_event() nua(0x7f95dc021300): event i_state 200 OK nua_stack.c:271 nua_stack_event() nua(0x7f95dc021300): event i_active 200 Call active nta.c:5744 incoming_free() nta: incoming_free(0x7f95dc020620) nua_stack.c:359 nua_application_event() nua: nua_application_event: entering tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2018-03-22 10:51:24.408777 [DEBUG] avcodec.c:1091 picture size changed from 352x288 to 1920x1080, reinitializing encoder frame I:1 Avg QP: 0.00 size: 1151 mb I I16..4: 99.0% 0.0% 1.0% coded y,uvDC,uvAC intra: 0.3% 0.0% 0.0% i16 v,h,dc,p: 79% 0% 21% 0% i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 0% 0% 100% 0% 0% 0% 0% 0% 0% i8c dc,h,v,p: 100% 0% 0% 0% kb/s:828.72 nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-03-22 10:51:24.418854 [DEBUG] sofia.c:7084 Channel sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com entering state [ready][200] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-03-22 10:51:24.418854 [DEBUG] switch_ivr.c:623 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Command Execute playback(tone_stream://%(100,3000,600)) using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 profile Constrained Baseline, level 3.1 EXECUTE sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com playback(tone_stream://%(100,3000,600)) 2018-03-22 10:51:24.468773 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@48000hz 1 channels 20ms 2018-03-22 10:51:24.468773 [INFO] switch_rtp.c:6737 Auto Changing audio RTCP port from 192.0.0.4:53201 to 24.114.108.163:57331 2018-03-22 10:51:24.468773 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 24.114.108.163:57331 2 2018-03-22 10:51:24.508869 [INFO] switch_rtp.c:6737 Auto Changing video RTCP port from 192.0.0.4:64247 to 24.114.108.163:57290 2018-03-22 10:51:24.508869 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 24.114.108.163:57290 2 tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc02e120): reset timer nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f961a882c60) nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 0/0 term, 1/1 free nta.c:1289 agent_timer() nta: timer not set 2018-03-22 10:51:24.838870 [DEBUG] switch_rtp.c:1887 rtcp_stats_init: audio ssrc[1045987720] base_seq[32317] 2018-03-22 10:51:25.038768 [INFO] switch_rtp.c:7268 Auto Changing audio port from 192.0.0.4:53200 to 24.114.108.163:57313 2018-03-22 10:51:27.538870 [DEBUG] switch_ivr_play_say.c:1942 done playing file tone_stream://%(100,3000,600) 2018-03-22 10:51:27.578900 [DEBUG] switch_ivr.c:623 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Command Execute playback(/stretto/current/mediaprompts//CONFERENCE/en_US/onlyparticipant.wav) EXECUTE sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com playback(/stretto/current/mediaprompts//CONFERENCE/en_US/onlyparticipant.wav) 2018-03-22 10:51:27.588779 [DEBUG] switch_core_file.c:342 File /stretto/current/mediaprompts//CONFERENCE/en_US/onlyparticipant.wav sample rate 8000 doesn't match requested rate 48000 2018-03-22 10:51:27.588779 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@48000hz 1 channels 20ms 2018-03-22 10:51:29.518876 [DEBUG] switch_rtp.c:1887 rtcp_stats_init: video ssrc[2603796608] base_seq[15540] freeswitch@bstnma-freeswitch6> uuid_kill [6fa735f3-f396-4893-bce4-9777442cce3b] 2018-03-22 10:51:30.398779 [DEBUG] switch_ivr_play_say.c:1942 done playing file /stretto/current/mediaprompts//CONFERENCE/en_US/onlyparticipant.wav freeswitch@bstnma-freeswitch6> uuid_kill 6fa735f3-f396-4893-bce4-9777442cce3b +OK 2018-03-22 10:51:31.178858 [NOTICE] switch_ivr.c:4269 Hangup sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com [CS_EXECUTE] [NORMAL_CLEARING] 2018-03-22 10:51:31.178858 [INFO] conference_loop.c:1471 Channel leaving conference, cause: NORMAL_CLEARING 2018-03-22 10:51:31.178858 [DEBUG] mod_conference.c:2247 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com skip receive message [UNBRIDGE] (channel is hungup already) 2018-03-22 10:51:31.178858 [DEBUG] switch_core_media.c:5970 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Video thread ended 2018-03-22 10:51:31.188781 [DEBUG] switch_core_media.c:9780 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com skip receive message [HARD_MUTE] (channel is hungup already) 2018-03-22 10:51:31.188781 [DEBUG] switch_core_codec.c:248 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Restore previous codec opus:116. 2018-03-22 10:51:31.188781 [DEBUG] switch_core_session.c:2815 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-03-22 10:51:31.188781 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State EXECUTE going to sleep 2018-03-22 10:51:31.188781 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Running State Change CS_HANGUP (Cur 1 Tot 3) 2018-03-22 10:51:31.188781 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Callstate Change ACTIVE -> HANGUP 2018-03-22 10:51:31.188781 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State HANGUP 2018-03-22 10:51:31.188781 [DEBUG] mod_sofia.c:438 Channel sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com hanging up, cause: NORMAL_CLEARING 2018-03-22 10:51:31.188781 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com nua.c:645 nua_bye() nua: nua_bye: entering nua_stack.c:529 nua_signal() nua(0x7f95dc021300): sent signal r_bye 2018-03-22 10:51:31.188781 [DEBUG] switch_core_state_machine.c:60 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Standard HANGUP, cause: NORMAL_CLEARING 2018-03-22 10:51:31.188781 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State HANGUP going to sleep nua_stack.c:569 nua_stack_signal() nua(0x7f95dc021300): recv signal r_bye nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f95dc0216b0, ...) called soa.c:1784 soa_terminate() soa_terminate(static::0x7f95dc0216b0) called soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f95dc0216b0) called 2018-03-22 10:51:31.188781 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State Change CS_HANGUP -> CS_REPORTING nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:3268 tport_tsend() tport_tsend(0x7f95dc004f40) XXXXX tpn = tls/192.0.0.4:53696 tport.c:4057 tport_resolve() tport_resolve addrinfo = 192.0.0.4:53696 tport.c:4691 tport_by_addrinfo() tport_by_addrinfo(0x7f95dc004f40): not found by name tls/192.0.0.4:53696 tport.c:862 tport_alloc_secondary() tport_alloc_secondary(0x7f95dc004f40): new secondary tport 0x7f95dc030270 tport_type_tcp.c:203 tport_tcp_init_secondary() tport_tcp_init_secondary(0x7f95dc030270): Setting TCP_KEEPIDLE to 30 tport_type_tcp.c:209 tport_tcp_init_secondary() tport_tcp_init_secondary(0x7f95dc030270): Setting TCP_KEEPINTVL to 30 2018-03-22 10:51:31.188781 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Running State Change CS_REPORTING (Cur 1 Tot 3) 2018-03-22 10:51:31.188781 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State REPORTING tport_type_tls.c:683 tport_tls_connect() tport_tls_connect(0x7f95dc030270): connecting to tls/192.0.0.4:53696/sips tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc030270): reset timer 2018-03-22 10:51:31.198773 [DEBUG] switch_core_state_machine.c:174 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Standard REPORTING, cause: NORMAL_CLEARING tport.c:3793 tport_queue() tport_queue(0x7f95dc030270): queueing 0x7f95dc03e9d0 for tls/192.0.0.4:53696 2018-03-22 10:51:31.198773 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State REPORTING going to sleep nta.c:8304 outgoing_send() nta: sent BYE (120529081) to tls/192.0.0.4:53696 tport.c:4171 tport_pend() tport_pend(0x7f95dc030270): pending 0x7f95dc03e9d0 for tls/192.0.0.4:53696 (already 0) nta.c:1350 set_timeout() nta: timer set to 32000 ms 2018-03-22 10:51:31.198773 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State Change CS_REPORTING -> CS_DESTROY 2018-03-22 10:51:31.198773 [DEBUG] switch_core_session.c:1665 Session 3 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Locked, Waiting on external entities 2018-03-22 10:51:31.198773 [NOTICE] switch_core_session.c:1683 Session 3 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Ended 2018-03-22 10:51:31.198773 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com [CS_DESTROY] 2018-03-22 10:51:31.198773 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) Running State Change CS_DESTROY (Cur 0 Tot 3) 2018-03-22 10:51:31.198773 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State DESTROY 2018-03-22 10:51:31.198773 [DEBUG] mod_sofia.c:343 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com SOFIA DESTROY 2018-03-22 10:51:31.198773 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[214] PLC[0] FEC[0] 2018-03-22 10:51:31.198773 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 2018-03-22 10:51:31.198773 [DEBUG] mod_opus.c:711 Opus decoder stats: Frames[0] PLC[0] FEC[0] 2018-03-22 10:51:31.198773 [DEBUG] mod_opus.c:726 Opus encoder stats: Frames[342] Bytes encoded[31418] Encoded length ms[6840] Average encoded bitrate bps[41890] frame I:10 Avg QP: 4.22 size: 17969 frame P:195 Avg QP: 1.01 size: 243 mb I I16..4: 97.5% 0.0% 2.5% mb P I16..4: 0.0% 0.0% 0.0% P16..4: 0.2% 0.0% 0.0% 0.0% 0.0% skip:99.8% coded y,uvDC,uvAC intra: 1.3% 1.1% 0.8% inter: 0.1% 0.0% 0.0% i16 v,h,dc,p: 79% 2% 20% 0% i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 28% 10% 52% 2% 2% 1% 1% 1% 2% i8c dc,h,v,p: 99% 0% 0% 0% kb/s:797.83 2018-03-22 10:51:31.198773 [DEBUG] switch_core_state_machine.c:181 sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com Standard DESTROY 2018-03-22 10:51:31.198773 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/guest_JamieStracha_3486d97@meetings6.softphone.com) State DESTROY going to sleep 2018-03-22 10:51:31.208800 [DEBUG] mod_conference.c:788 Write Lock ON 2018-03-22 10:51:31.208800 [DEBUG] mod_conference.c:791 Write Lock OFF tport_tls.c:956 tls_connect() tls_connect(0x7f95dc030270): events CONNECTING ERROR HANGUP tport.c:4233 tport_release() tport_release(0x7f95dc030270): 0x7f95dc03e9d0 by 0x7f95dc022950 with (nil) nta.c:8496 outgoing_print_tport_error() nta: BYE (120529081): Network is unreachable (101) with tls/[192.0.0.4]:53696 nua_stack.c:271 nua_stack_event() nua(0x7f95dc021300): event r_bye 503 Service Unavailable nua_session.c:4139 signal_call_state_change() nua(0x7f95dc021300): call state changed: terminating -> terminated nua_stack.c:271 nua_stack_event() nua(0x7f95dc021300): event i_state 503 to BYE nua_stack.c:271 nua_stack_event() nua(0x7f95dc021300): event i_terminated 503 to BYE nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f95dc021300): removing session usage soa.c:356 soa_destroy() soa_destroy(static::0x7f95dc0216b0) called nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f95dc022e80) nua_session.c:351 nua_session_usage_destroy() nua: terminated session 0x7f95dc021300 nta.c:8722 outgoing_free() nta: outgoing_free(0x7f95dc022950) tport.c:2307 tport_set_secondary_timer() tport(0x7f95dc030270): reset timer nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:529 nua_signal() nua(0x7f95dc021300): sent signal r_destroy tport.c:2101 tport_close() tport_close(0x7f95dc030270): tls/192.0.0.4:53696/sips tport_tls.c:157 tls_log_errors() tls_free: 140e0114:SSL routines:SSL_shutdown:uninitialized nua_stack.c:569 nua_stack_signal() nua(0x7f95dc021300): recv signal r_destroy nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) freeswitch@bstnma-freeswitch6> /exit