Asterisk Ready. *CLI> core set debug 5 Core debug was OFF and is now 5. *CLI> [2021-03-14 18:13:54] DEBUG[339]: chan_sip.c:9470 __find_call: = Looking for Call ID: 8GLAGCARMT0NRFDL3UIPOU5O40@81.201.85.47-b2b_1 (Checking From) --From tag 225a22219200fd10c93a581ba66c7fbd --To-tag [2021-03-14 18:13:54] DEBUG[339]: acl.c:990 ast_ouraddrfor: For destination '169.48.232.158', our source address is '192.168.1.101'. [2021-03-14 18:13:54] DEBUG[339]: chan_sip.c:3958 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 192.168.1.101:5060 [2021-03-14 18:13:54] DEBUG[339]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '169.48.232.158:5060' into... [2021-03-14 18:13:54] DEBUG[339]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '169.48.232.158' and port '5060'. [2021-03-14 18:13:54] DEBUG[339]: chan_sip.c:9063 __sip_alloc: Allocating new SIP dialog for 8GLAGCARMT0NRFDL3UIPOU5O40@81.201.85.47-b2b_1 - INVITE (No RTP) [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:29085 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '169.48.232.158:5060' into... [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '169.48.232.158' and port '5060'. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '169.48.232.158' into... [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '169.48.232.158' and port ''. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:526 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7f039c007450' [2021-03-14 18:13:54] DEBUG[339][C-00000001]: res_rtp_asterisk.c:3661 rtp_allocate_transport: Allocated port 11026 for RTP instance '0x7f039c007450' [2021-03-14 18:13:54] DEBUG[339][C-00000001]: res_rtp_asterisk.c:3691 rtp_allocate_transport: Creating ICE session 0.0.0.0:11026 (11026) for RTP instance '0x7f039c007450' [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '192.168.1.101' into... [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '192.168.1.101' and port ''. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '192.168.1.101' into... [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '192.168.1.101' and port ''. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:543 ast_rtp_instance_new: RTP instance '0x7f039c007450' is setup and ready to go [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'timeline-server' into... [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'timeline-server' and port ''. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '192.168.1.101' into... [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '192.168.1.101' and port ''. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '192.168.1.101' into... [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '192.168.1.101' and port ''. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: res_rtp_asterisk.c:7937 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7f039c007450' == Using SIP RTP CoS mark 5 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:5847 do_setnat: Setting NAT on RTP to On [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10376 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10376 process_sdp: Processing session-level SDP o=- 98768722 98768722 IN IP4 81.201.85.86... OK. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10376 process_sdp: Processing session-level SDP s=session... UNSUPPORTED OR FAILED. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '81.201.85.86' into... [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '81.201.85.86' and port ''. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10376 process_sdp: Processing session-level SDP c=IN IP4 81.201.85.86... OK. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10376 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1319 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 0 based on m type on 0x7f044c17cfa0 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1319 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 18 based on m type on 0x7f044c17cfa0 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1319 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 8 based on m type on 0x7f044c17cfa0 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10847 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10847 process_sdp: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10847 process_sdp: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10847 process_sdp: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10847 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10847 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED OR FAILED. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10847 process_sdp: Processing media-level (audio) SDP a=ptime:20... OK. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10847 process_sdp: Processing media-level (audio) SDP a=maxptime:150... UNSUPPORTED OR FAILED. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:10847 process_sdp: Processing media-level (audio) SDP a=sendrecv... OK. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1283 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 0 (0x7f039c02bd28) from 0x7f044c17cfa0 to 0x7f044c17cfa0 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1283 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 8 (0x7f039c0265b8) from 0x7f044c17cfa0 to 0x7f044c17cfa0 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1283 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 18 (0x7f039c026568) from 0x7f044c17cfa0 to 0x7f044c17cfa0 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1283 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 101 (0x7f039c026638) from 0x7f044c17cfa0 to 0x7f044c17cfa0 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: acl.c:990 ast_ouraddrfor: For destination '81.201.85.86', our source address is '192.168.1.101'. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: res_rtp_asterisk.c:8020 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7f039c007450' > 0x7f039c0083d0 -- Strict RTP learning after remote address set to: 81.201.85.86:12956 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1120 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 0 (0x7f039c02bd28) from 0x7f044c17cfa0 to 0x7f039c007628 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1120 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 8 (0x7f039c0265b8) from 0x7f044c17cfa0 to 0x7f039c007628 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1120 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 18 (0x7f039c026568) from 0x7f044c17cfa0 to 0x7f039c007628 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1120 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 101 (0x7f039c026638) from 0x7f044c17cfa0 to 0x7f039c007628 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1205 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 0 (0x7f039c02bd28) from 0x7f044c17cfa0 to 0x7f039c007628 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1205 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 8 (0x7f039c0265b8) from 0x7f044c17cfa0 to 0x7f039c007628 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1205 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 18 (0x7f039c026568) from 0x7f044c17cfa0 to 0x7f039c007628 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: rtp_engine.c:1205 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 101 (0x7f039c026638) from 0x7f044c17cfa0 to 0x7f039c007628 [2021-03-14 18:13:54] DEBUG[339][C-00000001]: res_rtp_asterisk.c:7836 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7f039c007450' [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:11161 process_sdp: We're settling with these formats: (ulaw|g729|alaw) [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:26656 handle_request_invite: Checking SIP call limits for device [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:6816 update_call_counter: Updating call counter for incoming call [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'timeline4ever.duckdns.org:5060' into... [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'timeline4ever.duckdns.org' and port ''. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '169.48.232.158' into... [2021-03-14 18:13:54] DEBUG[339][C-00000001]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '169.48.232.158' and port ''. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: stasis.c:572 stasis_topic_create_with_detail: Creating topic. name: channel:1615760034.0, detail: [2021-03-14 18:13:54] DEBUG[339][C-00000001]: stasis.c:606 stasis_topic_create_with_detail: Topic 'channel:1615760034.0': 0x7f039c02b9b0 created [2021-03-14 18:13:54] DEBUG[339][C-00000001]: stasis.c:572 stasis_topic_create_with_detail: Creating topic. name: cache:9/channel:1615760034.0, detail: [2021-03-14 18:13:54] DEBUG[339][C-00000001]: stasis.c:606 stasis_topic_create_with_detail: Topic 'cache:9/channel:1615760034.0': 0x7f039c02bc00 created [2021-03-14 18:13:54] DEBUG[339][C-00000001]: channel.c:989 __ast_channel_alloc_ap: Channel 0x7f039c0325f0 'SIP/anveo_direct_in_169.48.232.158-00000000' allocated [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:8216 sip_new: *** Our native formats are (ulaw) [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:8217 sip_new: *** Joint capabilities are (ulaw|g729|alaw) [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:8218 sip_new: *** Our capabilities are (ulaw|g729|alaw) [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:8219 sip_new: *** AST_CODEC_CHOOSE formats are ulaw [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:8252 sip_new: This channel will not be able to handle video. [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:26861 handle_request_invite: SIP/anveo_direct_in_169.48.232.158-00000000: New call is still down.... Trying... [2021-03-14 18:13:54] DEBUG[339][C-00000001]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 100' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:13:54] DEBUG[32749]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for SIP - anveo_direct_in_169.48.232.158 [2021-03-14 18:13:54] DEBUG[32749]: chan_sip.c:30621 sip_devicestate: Checking device state for peer anveo_direct_in_169.48.232.158 [2021-03-14 18:13:54] DEBUG[32749]: devicestate.c:466 do_state_change: Changing state for SIP/anveo_direct_in_169.48.232.158 - state 1 (Not in use) [2021-03-14 18:13:54] DEBUG[32749]: stasis.c:572 stasis_topic_create_with_detail: Creating topic. name: devicestate:all/SIP/anveo_direct_in_169.48.232.158, detail: [2021-03-14 18:13:54] DEBUG[32749]: stasis.c:606 stasis_topic_create_with_detail: Topic 'devicestate:all/SIP/anveo_direct_in_169.48.232.158': 0x7f048c001f20 created [2021-03-14 18:13:54] DEBUG[360][C-00000001]: pbx.c:2938 pbx_extension_helper: Launching 'Ringing' [2021-03-14 18:13:54] DEBUG[357]: app_queue.c:2591 device_state_cb: Device 'SIP/anveo_direct_in_169.48.232.158' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. -- Executing [15144182449@from-anveo-direct:1] Ringing("SIP/anveo_direct_in_169.48.232.158-00000000", "") in new stack [2021-03-14 18:13:54] DEBUG[360][C-00000001]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 180' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:13:54] DEBUG[360][C-00000001]: pbx_variables.c:761 pbx_substitute_variables_helper_full: Function SIP_HEADER(X-anveo-e164) result is '15144182449' [2021-03-14 18:13:54] DEBUG[360][C-00000001]: pbx.c:2938 pbx_extension_helper: Launching 'Goto' -- Executing [15144182449@from-anveo-direct:2] Goto("SIP/anveo_direct_in_169.48.232.158-00000000", "from-trunk,15144182449,1") in new stack -- Goto (from-trunk,15144182449,1) [2021-03-14 18:13:54] DEBUG[360][C-00000001]: pbx_variables.c:379 ast_str_retrieve_variable: Result of 'EXTEN' is '15144182449' [2021-03-14 18:13:54] DEBUG[360][C-00000001]: pbx.c:2938 pbx_extension_helper: Launching 'NoOp' -- Executing [15144182449@from-trunk:1] NoOp("SIP/anveo_direct_in_169.48.232.158-00000000", "From Anveo 15144182449") in new stack [2021-03-14 18:13:54] DEBUG[360][C-00000001]: pbx.c:2938 pbx_extension_helper: Launching 'Ringing' -- Executing [15144182449@from-trunk:2] Ringing("SIP/anveo_direct_in_169.48.232.158-00000000", "") in new stack [2021-03-14 18:13:54] DEBUG[360][C-00000001]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 180' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:13:54] DEBUG[360][C-00000001]: pbx.c:2938 pbx_extension_helper: Launching 'Wait' -- Executing [15144182449@from-trunk:3] Wait("SIP/anveo_direct_in_169.48.232.158-00000000", "2") in new stack [2021-03-14 18:13:56] DEBUG[360][C-00000001]: pbx.c:2938 pbx_extension_helper: Launching 'Answer' -- Executing [15144182449@from-trunk:4] Answer("SIP/anveo_direct_in_169.48.232.158-00000000", "") in new stack [2021-03-14 18:13:56] DEBUG[360][C-00000001]: chan_sip.c:7461 sip_answer: SIP answering channel: SIP/anveo_direct_in_169.48.232.158-00000000 [2021-03-14 18:13:56] DEBUG[360][C-00000001]: res_rtp_asterisk.c:4160 ast_rtp_update_source: Setting the marker bit due to a source update [2021-03-14 18:13:56] DEBUG[32749]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for SIP - anveo_direct_in_169.48.232.158 [2021-03-14 18:13:56] DEBUG[32749]: chan_sip.c:30621 sip_devicestate: Checking device state for peer anveo_direct_in_169.48.232.158 [2021-03-14 18:13:56] DEBUG[32749]: devicestate.c:466 do_state_change: Changing state for SIP/anveo_direct_in_169.48.232.158 - state 1 (Not in use) [2021-03-14 18:13:56] DEBUG[360][C-00000001]: chan_sip.c:13588 add_sdp: ** Our capability: (ulaw|g729|alaw) Video flag: True Text flag: True [2021-03-14 18:13:56] DEBUG[360][C-00000001]: chan_sip.c:13589 add_sdp: ** Our prefcodec: (nothing) [2021-03-14 18:13:56] DEBUG[360][C-00000001]: chan_sip.c:13760 add_sdp: -- Done with adding codecs to SDP [2021-03-14 18:13:56] DEBUG[360][C-00000001]: chan_sip.c:13785 add_sdp: Setting framing on incoming call: 0 [2021-03-14 18:13:56] DEBUG[360][C-00000001]: res_rtp_asterisk.c:1189 ast_rtp_ice_set_role: Set role to CONTROLLED (0x7f039c007450) [2021-03-14 18:13:56] DEBUG[360][C-00000001]: chan_sip.c:13979 add_sdp: Done building SDP. Settling with this capability: (ulaw|g729|alaw) [2021-03-14 18:13:56] DEBUG[360][C-00000001]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:13:56] DEBUG[339]: chan_sip.c:4082 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #13)) [2021-03-14 18:13:56] DEBUG[339]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:13:56] DEBUG[360][C-00000001]: channel.c:2740 __ast_answer: Didn't receive a media frame from SIP/anveo_direct_in_169.48.232.158-00000000 within 500 ms of answering. Continuing anyway [2021-03-14 18:13:56] DEBUG[360][C-00000001]: pbx.c:2938 pbx_extension_helper: Launching 'BackGround' -- Executing [15144182449@from-trunk:5] BackGround("SIP/anveo_direct_in_169.48.232.158-00000000", "abandon-all-hope") in new stack [2021-03-14 18:13:56] DEBUG[360][C-00000001]: media_cache.c:236 ast_media_cache_retrieve: Failed to obtain media at 'abandon-all-hope' [2021-03-14 18:13:56] DEBUG[360][C-00000001]: channel.c:5744 set_format: Channel SIP/anveo_direct_in_169.48.232.158-00000000 setting write format path: ulaw -> ulaw [2021-03-14 18:13:56] DEBUG[360][C-00000001]: channel.c:3213 ast_settimeout_full: Scheduling timer at (50 requested / 50 actual) timer ticks per second -- Playing 'abandon-all-hope.ulaw' (language 'en') [2021-03-14 18:13:57] DEBUG[339]: chan_sip.c:4082 retrans_pkt: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #13)) [2021-03-14 18:13:57] DEBUG[339]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:13:59] DEBUG[339]: chan_sip.c:4082 retrans_pkt: ** SIP timers: Rescheduling retransmission 4 to 4000 ms (t1 500 ms (Retrans id #13)) [2021-03-14 18:13:59] DEBUG[339]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:13:59] DEBUG[360][C-00000001]: channel.c:3213 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second [2021-03-14 18:13:59] DEBUG[360][C-00000001]: channel.c:3213 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second [2021-03-14 18:13:59] DEBUG[360][C-00000001]: channel.c:3213 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second [2021-03-14 18:13:59] DEBUG[360][C-00000001]: channel.c:5744 set_format: Channel SIP/anveo_direct_in_169.48.232.158-00000000 setting write format path: ulaw -> ulaw -- Auto fallthrough, channel 'SIP/anveo_direct_in_169.48.232.158-00000000' status is 'UNKNOWN' [2021-03-14 18:13:59] DEBUG[360][C-00000001]: channel.c:2475 ast_softhangup_nolock: Soft-Hanging (0x10) up channel 'SIP/anveo_direct_in_169.48.232.158-00000000' [2021-03-14 18:13:59] DEBUG[360][C-00000001]: channel.c:2566 ast_hangup: Channel 0x7f039c0325f0 'SIP/anveo_direct_in_169.48.232.158-00000000' hanging up. Refs: 2 [2021-03-14 18:13:59] DEBUG[360][C-00000001]: chan_sip.c:7203 sip_hangup: Hangup call SIP/anveo_direct_in_169.48.232.158-00000000, SIP callid 8GLAGCARMT0NRFDL3UIPOU5O40@81.201.85.47-b2b_1 [2021-03-14 18:13:59] DEBUG[360][C-00000001]: channel.c:2211 ast_channel_destructor: Channel 0x7f039c0325f0 'SIP/anveo_direct_in_169.48.232.158-00000000' destroying [2021-03-14 18:13:59] DEBUG[32757]: cdr.c:1476 cdr_object_finalize: Finalized CDR for SIP/anveo_direct_in_169.48.232.158-00000000 - start 1615760034.334721 answer 1615760036.338686 end 1615760039.920935 dispo ANSWERED [2021-03-14 18:13:59] DEBUG[360][C-00000001]: stasis.c:438 topic_dtor: Destroying topic. name: cache:9/channel:1615760034.0, detail: [2021-03-14 18:13:59] DEBUG[360][C-00000001]: stasis.c:446 topic_dtor: Topic 'cache:9/channel:1615760034.0': 0x7f039c02bc00 destroyed [2021-03-14 18:13:59] DEBUG[360][C-00000001]: stasis.c:438 topic_dtor: Destroying topic. name: channel:1615760034.0, detail: [2021-03-14 18:13:59] DEBUG[360][C-00000001]: stasis.c:446 topic_dtor: Topic 'channel:1615760034.0': 0x7f039c02b9b0 destroyed [2021-03-14 18:13:59] DEBUG[32757]: stasis.c:572 stasis_topic_create_with_detail: Creating topic. name: channel:1615760039.1, detail: [2021-03-14 18:13:59] DEBUG[32757]: stasis.c:606 stasis_topic_create_with_detail: Topic 'channel:1615760039.1': 0x7f04380039b0 created [2021-03-14 18:13:59] DEBUG[32757]: stasis.c:572 stasis_topic_create_with_detail: Creating topic. name: cache:10/channel:1615760039.1, detail: [2021-03-14 18:13:59] DEBUG[32749]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for SIP - anveo_direct_in_169.48.232.158 [2021-03-14 18:13:59] DEBUG[32757]: stasis.c:606 stasis_topic_create_with_detail: Topic 'cache:10/channel:1615760039.1': 0x7f0438004420 created [2021-03-14 18:13:59] DEBUG[32749]: chan_sip.c:30621 sip_devicestate: Checking device state for peer anveo_direct_in_169.48.232.158 [2021-03-14 18:13:59] DEBUG[32749]: devicestate.c:466 do_state_change: Changing state for SIP/anveo_direct_in_169.48.232.158 - state 1 (Not in use) [2021-03-14 18:13:59] DEBUG[32757]: stasis.c:438 topic_dtor: Destroying topic. name: cache:10/channel:1615760039.1, detail: [2021-03-14 18:13:59] DEBUG[32757]: stasis.c:446 topic_dtor: Topic 'cache:10/channel:1615760039.1': 0x7f0438004420 destroyed [2021-03-14 18:13:59] DEBUG[32757]: stasis.c:438 topic_dtor: Destroying topic. name: channel:1615760039.1, detail: [2021-03-14 18:13:59] DEBUG[32757]: stasis.c:446 topic_dtor: Topic 'channel:1615760039.1': 0x7f04380039b0 destroyed [2021-03-14 18:14:03] DEBUG[339]: chan_sip.c:4082 retrans_pkt: ** SIP timers: Rescheduling retransmission 5 to 4000 ms (t1 500 ms (Retrans id #13)) [2021-03-14 18:14:03] DEBUG[339]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:14:07] DEBUG[32742]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying. [2021-03-14 18:14:07] DEBUG[32741]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying. [2021-03-14 18:14:07] DEBUG[32737]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 3 [2021-03-14 18:14:07] DEBUG[32743]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying. [2021-03-14 18:14:07] DEBUG[32737]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 2 [2021-03-14 18:14:07] DEBUG[32737]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 4 [2021-03-14 18:14:07] DEBUG[32740]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying. [2021-03-14 18:14:07] DEBUG[32737]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 1 [2021-03-14 18:14:07] DEBUG[339]: chan_sip.c:4082 retrans_pkt: ** SIP timers: Rescheduling retransmission 6 to 4000 ms (t1 500 ms (Retrans id #13)) [2021-03-14 18:14:07] DEBUG[339]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:14:11] DEBUG[339]: chan_sip.c:4082 retrans_pkt: ** SIP timers: Rescheduling retransmission 7 to 4000 ms (t1 500 ms (Retrans id #13)) [2021-03-14 18:14:11] DEBUG[339]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:14:15] DEBUG[339]: chan_sip.c:4082 retrans_pkt: ** SIP timers: Rescheduling retransmission 8 to 4000 ms (t1 500 ms (Retrans id #13)) [2021-03-14 18:14:15] DEBUG[339]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:14:17] DEBUG[314]: res_pjsip_registrar.c:1279 check_expiration_thread: Woke up at 1615760057 Interval: 30 [2021-03-14 18:14:17] DEBUG[314]: res_pjsip_registrar.c:1286 check_expiration_thread: Expiring 0 contacts [2021-03-14 18:14:19] DEBUG[339]: chan_sip.c:4082 retrans_pkt: ** SIP timers: Rescheduling retransmission 9 to 4000 ms (t1 500 ms (Retrans id #13)) [2021-03-14 18:14:19] DEBUG[339]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:14:19] DEBUG[32739]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying. [2021-03-14 18:14:19] DEBUG[32737]: threadpool.c:1028 worker_thread_destroy: Destroying worker thread 0 [2021-03-14 18:14:21] DEBUG[339]: chan_sip.c:9470 __find_call: = Looking for Call ID: 8GLAGCARMT0NRFDL3UIPOU5O40@81.201.85.47-b2b_1 (Checking From) --From tag 225a22219200fd10c93a581ba66c7fbd --To-tag as33d03d2b [2021-03-14 18:14:21] DEBUG[339][C-00000001]: chan_sip.c:29085 handle_incoming: **** Received BYE (8) - Command in SIP BYE [2021-03-14 18:14:21] DEBUG[339][C-00000001]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 487' onto UDP socket destined for 169.48.232.158:5060 [2021-03-14 18:14:21] DEBUG[339][C-00000001]: chan_sip.c:4585 __sip_ack: Stopping retransmission on '8GLAGCARMT0NRFDL3UIPOU5O40@81.201.85.47-b2b_1' of Response 200: Match Found [2021-03-14 18:14:21] DEBUG[339][C-00000001]: chan_sip.c:4585 __sip_ack: Stopping retransmission on '8GLAGCARMT0NRFDL3UIPOU5O40@81.201.85.47-b2b_1' of Response 200: Match Found [2021-03-14 18:14:21] DEBUG[339][C-00000001]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '169.48.232.158:5060' into... [2021-03-14 18:14:21] DEBUG[339][C-00000001]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '169.48.232.158' and port '5060'. [2021-03-14 18:14:21] DEBUG[339][C-00000001]: chan_sip.c:3457 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 8GLAGCARMT0NRFDL3UIPOU5O40@81.201.85.47-b2b_1 [2021-03-14 18:14:21] DEBUG[339][C-00000001]: chan_sip.c:27686 handle_request_bye: Received bye, no owner, selfdestruct soon. [2021-03-14 18:14:21] DEBUG[339][C-00000001]: chan_sip.c:3801 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 169.48.232.158:5060