[Aug 18 12:12:18] Asterisk 18.4.0 built by sip_admin @ sipserver on a x86_64 running Linux on 2021-06-02 05:25:24 UTC [Aug 18 12:12:18] VERBOSE[1269] loader.c: Reloading module 'logger' (Logger) [Aug 18 12:12:18] DEBUG[1269] config.c: Parsing /etc/asterisk/logger.conf [Aug 18 12:12:18] VERBOSE[1269] logger.c: Asterisk Queue Logger restarted [Aug 18 12:12:44] DEBUG[845] res_pjsip_registrar.c: Woke up at 1629256364 Interval: 30 [Aug 18 12:12:44] DEBUG[845] res_pjsip_registrar.c: Expiring 0 contacts [Aug 18 12:12:54] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP request (578 bytes) from UDP:192.168.10.121:5060 ---> REGISTER sip:asrterisk@192.168.10.125 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.121:5060;rport;branch=z9hG4bKPj1c67956f-4afd-44c8-b458-a89176b792c0 Max-Forwards: 70 From: ;tag=8a9b3c02-e5dc-4e93-82fa-087bda2efe82 To: Call-ID: 7041eefe-dcc3-42f0-8a63-cb13dc7f05bb CSeq: 37353 REGISTER User-Agent: PJSUA v2.9-svn Linux-5.8.0.63/x86_64/glibc-2.31 Contact: Expires: 300 Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Content-Length: 0 [Aug 18 12:12:54] DEBUG[833] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg REGISTER/cseq=37353 (rdata0x7f6c8c003458) [Aug 18 12:12:54] DEBUG[833] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000024 to use for Request msg REGISTER/cseq=37353 (rdata0x7f6c8c003458) [Aug 18 12:12:54] DEBUG[831] threadpool.c: Increasing threadpool pjsip/pool's size by 5 [Aug 18 12:12:54] DEBUG[1888] netsock2.c: Splitting '192.168.10.121' into... [Aug 18 12:12:54] DEBUG[1888] netsock2.c: ...host '192.168.10.121' and port ''. [Aug 18 12:12:54] DEBUG[1888] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Aug 18 12:12:54] DEBUG[1888] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '20002' domain '192.168.10.121' [Aug 18 12:12:54] DEBUG[1888] res_pjsip_endpoint_identifier_user.c: Identified by From username '20002' domain '192.168.10.121' [Aug 18 12:12:54] DEBUG[1888] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '20002'. [Aug 18 12:12:54] DEBUG[1888] netsock2.c: Splitting '192.168.10.125' into... [Aug 18 12:12:54] DEBUG[1888] netsock2.c: ...host '192.168.10.125' and port ''. [Aug 18 12:12:54] DEBUG[1888] netsock2.c: Splitting '192.168.10.121' into... [Aug 18 12:12:54] DEBUG[1888] netsock2.c: ...host '192.168.10.121' and port ''. [Aug 18 12:12:54] VERBOSE[1888] res_pjsip_logger.c: <--- Transmitting SIP response (575 bytes) to UDP:192.168.10.121:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.10.121:5060;rport=5060;received=192.168.10.121;branch=z9hG4bKPj1c67956f-4afd-44c8-b458-a89176b792c0 Call-ID: 7041eefe-dcc3-42f0-8a63-cb13dc7f05bb From: ;tag=8a9b3c02-e5dc-4e93-82fa-087bda2efe82 To: ;tag=z9hG4bKPj1c67956f-4afd-44c8-b458-a89176b792c0 CSeq: 37353 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1629256374/544a3687d6a98fb5fdf0b4cce479218a",opaque="1998682055e40d50",algorithm=md5,qop="auth" Server: Asterisk PBX 18.4.0 Content-Length: 0 [Aug 18 12:12:54] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP request (878 bytes) from UDP:192.168.10.121:5060 ---> REGISTER sip:asrterisk@192.168.10.125 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.121:5060;rport;branch=z9hG4bKPje7a9a9e5-0b21-4cdb-b2cb-4aaa245249a5 Max-Forwards: 70 From: ;tag=8a9b3c02-e5dc-4e93-82fa-087bda2efe82 To: Call-ID: 7041eefe-dcc3-42f0-8a63-cb13dc7f05bb CSeq: 37354 REGISTER User-Agent: PJSUA v2.9-svn Linux-5.8.0.63/x86_64/glibc-2.31 Contact: Expires: 300 Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Authorization: Digest username="20002", realm="asterisk", nonce="1629256374/544a3687d6a98fb5fdf0b4cce479218a", uri="sip:asrterisk@192.168.10.125", response="b86c21a755c99f7c96bc7d742cd8a10c", algorithm=md5, cnonce="3b87c598b7cc4be1b5dcc5536e97b0b9", opaque="1998682055e40d50", qop=auth, nc=00000001 Content-Length: 0 [Aug 18 12:12:54] DEBUG[833] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg REGISTER/cseq=37354 (rdata0x7f6c8c003458) [Aug 18 12:12:54] DEBUG[833] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000024 to use for Request msg REGISTER/cseq=37354 (rdata0x7f6c8c003458) [Aug 18 12:12:54] DEBUG[1888] netsock2.c: Splitting '192.168.10.121' into... [Aug 18 12:12:54] DEBUG[1888] netsock2.c: ...host '192.168.10.121' and port ''. [Aug 18 12:12:54] DEBUG[1888] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Aug 18 12:12:54] DEBUG[1888] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '20002' domain '192.168.10.121' [Aug 18 12:12:54] DEBUG[1888] res_pjsip_endpoint_identifier_user.c: Identified by From username '20002' domain '192.168.10.121' [Aug 18 12:12:54] DEBUG[1888] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '20002'. [Aug 18 12:12:54] DEBUG[1888] res_pjsip_authenticator_digest.c: Calculated nonce 1629256374/544a3687d6a98fb5fdf0b4cce479218a. Actual nonce is 1629256374/544a3687d6a98fb5fdf0b4cce479218a [Aug 18 12:12:54] DEBUG[1888] netsock2.c: Splitting '192.168.10.125' into... [Aug 18 12:12:54] DEBUG[1888] netsock2.c: ...host '192.168.10.125' and port ''. [Aug 18 12:12:54] DEBUG[1888] netsock2.c: Splitting '192.168.10.121' into... [Aug 18 12:12:54] DEBUG[1888] netsock2.c: ...host '192.168.10.121' and port ''. [Aug 18 12:12:54] DEBUG[1888] res_pjsip_registrar.c: Matched id '20002' to aor '20002' [Aug 18 12:12:54] DEBUG[1888] res_pjsip_registrar.c: Matched aor '20002' by To username [Aug 18 12:12:54] DEBUG[1888] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Aug 18 12:12:54] DEBUG[1888] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Aug 18 12:12:54] DEBUG[1888] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Aug 18 12:12:54] DEBUG[1888] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Aug 18 12:12:54] DEBUG[1888] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Aug 18 12:12:54] DEBUG[1888] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Aug 18 12:12:54] DEBUG[1888] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Aug 18 12:12:54] DEBUG[1888] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Aug 18 12:12:54] DEBUG[1888] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Aug 18 12:12:54] DEBUG[1888] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Aug 18 12:12:54] DEBUG[743] threadpool.c: Increasing threadpool sorcery/pool's size by 1 [Aug 18 12:12:54] DEBUG[1888] res_pjsip_registrar.c: Refreshed contact 'sip:20002@192.168.10.121:5060;ob' on AOR '20002' with new expiration of 300 seconds [Aug 18 12:12:54] VERBOSE[1888] res_pjsip_logger.c: <--- Transmitting SIP response (527 bytes) to UDP:192.168.10.121:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.121:5060;rport=5060;received=192.168.10.121;branch=z9hG4bKPje7a9a9e5-0b21-4cdb-b2cb-4aaa245249a5 Call-ID: 7041eefe-dcc3-42f0-8a63-cb13dc7f05bb From: ;tag=8a9b3c02-e5dc-4e93-82fa-087bda2efe82 To: ;tag=z9hG4bKPje7a9a9e5-0b21-4cdb-b2cb-4aaa245249a5 CSeq: 37354 REGISTER Date: Wed, 18 Aug 2021 03:12:54 GMT Contact: ;expires=299 Expires: 300 Server: Asterisk PBX 18.4.0 Content-Length: 0 [Aug 18 12:13:14] DEBUG[845] res_pjsip_registrar.c: Woke up at 1629256394 Interval: 30 [Aug 18 12:13:14] DEBUG[845] res_pjsip_registrar.c: Expiring 0 contacts [Aug 18 12:13:44] DEBUG[845] res_pjsip_registrar.c: Woke up at 1629256424 Interval: 30 [Aug 18 12:13:44] DEBUG[845] res_pjsip_registrar.c: Expiring 0 contacts [Aug 18 12:13:54] DEBUG[1891] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 18 12:13:54] DEBUG[1892] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 18 12:13:54] DEBUG[1890] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 18 12:13:54] DEBUG[1889] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 18 12:13:54] DEBUG[831] threadpool.c: Destroying worker thread 124 [Aug 18 12:13:54] DEBUG[831] threadpool.c: Destroying worker thread 125 [Aug 18 12:13:54] DEBUG[831] threadpool.c: Destroying worker thread 123 [Aug 18 12:13:54] DEBUG[831] threadpool.c: Destroying worker thread 122 [Aug 18 12:13:54] DEBUG[1888] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 18 12:13:54] DEBUG[1893] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 18 12:13:54] DEBUG[743] threadpool.c: Destroying worker thread 126 [Aug 18 12:13:54] DEBUG[831] threadpool.c: Destroying worker thread 121 [Aug 18 12:14:10] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP request (1479 bytes) from UDP:192.168.10.120:5060 ---> INVITE sip:20002@192.168.10.125 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.120:5060;rport;branch=z9hG4bKPj4c3acce7-f9f0-40aa-ad28-4eeea7a766ee Max-Forwards: 70 From: sip:20001@192.168.10.120;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 To: sip:20002@192.168.10.125 Contact: Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e CSeq: 16571 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800 Min-SE: 90 User-Agent: PJSUA v2.9-svn Linux-5.11.0.27/x86_64/glibc-2.31 Content-Type: application/sdp Content-Length: 809 v=0 o=- 3838245250 3838245250 IN IP4 192.168.10.120 s=pjmedia b=AS:117 t=0 0 a=X-nat:0 m=audio 4002 RTP/AVP 0 96 97 98 3 99 8 9 100 101 102 120 121 122 123 c=IN IP4 192.168.10.120 b=TIAS:96000 a=rtcp:4003 IN IP4 192.168.10.120 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:96 speex/16000 a=rtpmap:97 speex/8000 a=rtpmap:98 iLBC/8000 a=fmtp:98 mode=30 a=rtpmap:3 GSM/8000 a=rtpmap:99 speex/32000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:100 AMR/8000 a=rtpmap:101 AMR-WB/16000 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1 a=rtpmap:120 telephone-event/8000 a=fmtp:120 0-16 a=rtpmap:121 telephone-event/16000 a=fmtp:121 0-16 a=rtpmap:122 telephone-event/32000 a=fmtp:122 0-16 a=rtpmap:123 telephone-event/48000 a=fmtp:123 0-16 a=ssrc:2046365698 cname:3193f1c15cf5d1ec [Aug 18 12:14:10] DEBUG[833] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg INVITE/cseq=16571 (rdata0x7f6c8c003458) [Aug 18 12:14:10] DEBUG[833] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000038 to use for Request msg INVITE/cseq=16571 (rdata0x7f6c8c003458) [Aug 18 12:14:10] DEBUG[831] threadpool.c: Increasing threadpool pjsip/pool's size by 5 [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '192.168.10.120' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '192.168.10.120' and port ''. [Aug 18 12:14:10] DEBUG[1898] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Aug 18 12:14:10] DEBUG[1898] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '20001' domain '192.168.10.120' [Aug 18 12:14:10] DEBUG[1898] res_pjsip_endpoint_identifier_user.c: Identified by From username '20001' domain '192.168.10.120' [Aug 18 12:14:10] DEBUG[1898] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '20001'. [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '192.168.10.125' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '192.168.10.125' and port ''. [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '192.168.10.120' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '192.168.10.120' and port ''. [Aug 18 12:14:10] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP response (573 bytes) to UDP:192.168.10.120:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.10.120:5060;rport=5060;received=192.168.10.120;branch=z9hG4bKPj4c3acce7-f9f0-40aa-ad28-4eeea7a766ee Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e From: ;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 To: ;tag=z9hG4bKPj4c3acce7-f9f0-40aa-ad28-4eeea7a766ee CSeq: 16571 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1629256450/e96acf9cba6f4980a93ecb9b690b2239",opaque="1c861b4f1680ed0c",algorithm=md5,qop="auth" Server: Asterisk PBX 18.4.0 Content-Length: 0 [Aug 18 12:14:10] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP request (392 bytes) from UDP:192.168.10.120:5060 ---> ACK sip:20002@192.168.10.125 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.120:5060;rport;branch=z9hG4bKPj4c3acce7-f9f0-40aa-ad28-4eeea7a766ee Max-Forwards: 70 From: sip:20001@192.168.10.120;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 To: sip:20002@192.168.10.125;tag=z9hG4bKPj4c3acce7-f9f0-40aa-ad28-4eeea7a766ee Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e CSeq: 16571 ACK Content-Length: 0 [Aug 18 12:14:10] DEBUG[833] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg ACK/cseq=16571 (rdata0x7f6c8c003458) [Aug 18 12:14:10] DEBUG[833] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000038 to use for Request msg ACK/cseq=16571 (rdata0x7f6c8c003458) [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '192.168.10.120' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '192.168.10.120' and port ''. [Aug 18 12:14:10] DEBUG[1898] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Aug 18 12:14:10] DEBUG[1898] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '20001' domain '192.168.10.120' [Aug 18 12:14:10] DEBUG[1898] res_pjsip_endpoint_identifier_user.c: Identified by From username '20001' domain '192.168.10.120' [Aug 18 12:14:10] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP request (1775 bytes) from UDP:192.168.10.120:5060 ---> INVITE sip:20002@192.168.10.125 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.120:5060;rport;branch=z9hG4bKPj2d4808f6-4ea6-418e-b05c-81bf1b4a4d61 Max-Forwards: 70 From: sip:20001@192.168.10.120;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 To: sip:20002@192.168.10.125 Contact: Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e CSeq: 16572 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800 Min-SE: 90 User-Agent: PJSUA v2.9-svn Linux-5.11.0.27/x86_64/glibc-2.31 Authorization: Digest username="20001", realm="asterisk", nonce="1629256450/e96acf9cba6f4980a93ecb9b690b2239", uri="sip:20002@192.168.10.125", response="253dc09fb9a5c050f6a6ee5b67e7d1fb", algorithm=md5, cnonce="5cb0f80d34b442809110f7425bd38f7b", opaque="1c861b4f1680ed0c", qop=auth, nc=00000001 Content-Type: application/sdp Content-Length: 809 v=0 o=- 3838245250 3838245250 IN IP4 192.168.10.120 s=pjmedia b=AS:117 t=0 0 a=X-nat:0 m=audio 4002 RTP/AVP 0 96 97 98 3 99 8 9 100 101 102 120 121 122 123 c=IN IP4 192.168.10.120 b=TIAS:96000 a=rtcp:4003 IN IP4 192.168.10.120 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:96 speex/16000 a=rtpmap:97 speex/8000 a=rtpmap:98 iLBC/8000 a=fmtp:98 mode=30 a=rtpmap:3 GSM/8000 a=rtpmap:99 speex/32000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:100 AMR/8000 a=rtpmap:101 AMR-WB/16000 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1 a=rtpmap:120 telephone-event/8000 a=fmtp:120 0-16 a=rtpmap:121 telephone-event/16000 a=fmtp:121 0-16 a=rtpmap:122 telephone-event/32000 a=fmtp:122 0-16 a=rtpmap:123 telephone-event/48000 a=fmtp:123 0-16 a=ssrc:2046365698 cname:3193f1c15cf5d1ec [Aug 18 12:14:10] DEBUG[833] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg INVITE/cseq=16572 (rdata0x7f6c8c003458) [Aug 18 12:14:10] DEBUG[833] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000038 to use for Request msg INVITE/cseq=16572 (rdata0x7f6c8c003458) [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '192.168.10.120' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '192.168.10.120' and port ''. [Aug 18 12:14:10] DEBUG[1898] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Aug 18 12:14:10] DEBUG[1898] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username '20001' domain '192.168.10.120' [Aug 18 12:14:10] DEBUG[1898] res_pjsip_endpoint_identifier_user.c: Identified by From username '20001' domain '192.168.10.120' [Aug 18 12:14:10] DEBUG[1898] res_pjsip_authenticator_digest.c: Using default realm 'asterisk' on incoming auth '20001'. [Aug 18 12:14:10] DEBUG[1898] res_pjsip_authenticator_digest.c: Calculated nonce 1629256450/e96acf9cba6f4980a93ecb9b690b2239. Actual nonce is 1629256450/e96acf9cba6f4980a93ecb9b690b2239 [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '192.168.10.125' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '192.168.10.125' and port ''. [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '192.168.10.120' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '192.168.10.120' and port ''. [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: (null session) Request: INVITE [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Request: [Aug 18 12:14:10] DEBUG[1898] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000038 to use for Request msg INVITE/cseq=16572 (rdata0x7f6c8c026988) [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: 20001 [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: Direct media no glare mitigation [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Call (UDP:192.168.10.120:5060) to extension '20002' sending 100 Trying [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Method is INVITE, Response is 100 Trying [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001 [Aug 18 12:14:10] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP response (371 bytes) to UDP:192.168.10.120:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.10.120:5060;rport=5060;received=192.168.10.120;branch=z9hG4bKPj2d4808f6-4ea6-418e-b05c-81bf1b4a4d61 Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e From: ;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 To: CSeq: 16572 INVITE Server: Asterisk PBX 18.4.0 Content-Length: 0 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001 Event: TSX_STATE Inv State: INCOMING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001()' [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c98036468) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: There is no transaction involved in this state change [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The current inv state is INCOMING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Source of transaction state change is TX_MSG [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001 TSX State: Proceeding Inv State: INCOMING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001()' [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c98036468) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f6c98036468 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The current transaction state is Proceeding [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The current inv state is INCOMING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001 TSX State: Proceeding Inv State: INCOMING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Topology: Pending: (null topology) Active: (null topology) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Media count: 1 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Processing stream 0 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Using audio-0 for new stream name [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Using new stream 0:audio-0:audio:sendrecv (nothing) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001 Adding position 0 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Creating new media session [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Setting media session as default for audio [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Done [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Negotiating incoming SDP media stream 0:audio-0:audio:sendrecv (nothing) using audio SDP handler [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: 20001 [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '192.168.10.120' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '192.168.10.120' and port ''. [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '0.0.0.0' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '0.0.0.0' and port ''. [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: Transport transport-udp bound to 0.0.0.0: Using it for RTP media. [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f6c94026c70' [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) RTP allocated port 14920 [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) ICE creating session 0.0.0.0:14920 (14920) [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) ICE create [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) ICE add system candidates [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '192.168.10.125' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '192.168.10.125' and port ''. [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) ICE add candidate: 192.168.10.125:14920, 2130706431 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: RTP instance '0x7f6c94026c70' is setup and ready to go [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) ICE stopped [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting 'sipserver' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host 'sipserver' and port ''. [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) RTCP setup on RTP instance [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: 20001 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: 20001 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Setting tx payload type 3 based on m type on 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Setting tx payload type 9 based on m type on 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session/pjsip_session_caps.c: '20001' Caps for incoming audio call with pref 'local' - remote: (ulaw|gsm|alaw|g722|speex16|speex|ilbc|speex32|opus) local: (ulaw) joint: (ulaw) [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Crossover copying tx to rx payload mapping 0 (0x7f6c94090ca8) from 0x7f6c7dc742a0 to 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Crossover copying tx to rx payload mapping 3 (0x7f6c940902e8) from 0x7f6c7dc742a0 to 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Crossover copying tx to rx payload mapping 8 (0x7f6c94090508) from 0x7f6c7dc742a0 to 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Crossover copying tx to rx payload mapping 9 (0x7f6c9408f338) from 0x7f6c7dc742a0 to 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Crossover copying tx to rx payload mapping 96 (0x7f6c94090cf8) from 0x7f6c7dc742a0 to 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Crossover copying tx to rx payload mapping 97 (0x7f6c94090d48) from 0x7f6c7dc742a0 to 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Crossover copying tx to rx payload mapping 98 (0x7f6c94090388) from 0x7f6c7dc742a0 to 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Crossover copying tx to rx payload mapping 99 (0x7f6c94090d98) from 0x7f6c7dc742a0 to 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Crossover copying tx to rx payload mapping 102 (0x7f6c9408f588) from 0x7f6c7dc742a0 to 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Crossover copying tx to rx payload mapping 120 (0x7f6c9408f4e8) from 0x7f6c7dc742a0 to 0x7f6c7dc742a0 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying rx payload mapping 0 (0x7f6c94090ca8) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying rx payload mapping 3 (0x7f6c940902e8) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying rx payload mapping 8 (0x7f6c94090508) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying rx payload mapping 9 (0x7f6c9408f338) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying rx payload mapping 96 (0x7f6c94090cf8) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying rx payload mapping 97 (0x7f6c94090d48) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying rx payload mapping 98 (0x7f6c94090388) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying rx payload mapping 99 (0x7f6c94090d98) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying rx payload mapping 102 (0x7f6c9408f588) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying rx payload mapping 120 (0x7f6c9408f4e8) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 0 (0x7f6c94090ca8) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 3 (0x7f6c940902e8) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 8 (0x7f6c94090508) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 9 (0x7f6c9408f338) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 96 (0x7f6c94090cf8) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 97 (0x7f6c94090d48) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 98 (0x7f6c94090388) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 99 (0x7f6c94090d98) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 102 (0x7f6c9408f588) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 120 (0x7f6c9408f4e8) from 0x7f6c7dc742a0 to 0x7f6c94026e48 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Media stream 0:audio-0:audio:sendrecv (ulaw) handled by audio [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Done with stream 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Handled? yes [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Processing streams [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Processing stream 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001 Adding position 0 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Using existing media_session [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001 Stream: 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: 20001 Type: audio 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) RTCP ignoring duplicate property [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: RC: 1 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Had handler [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Stream 0:audio-0:audio:sendrecv (ulaw) added [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Done with 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Adding bundle groups (if available) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Copying connection details [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Processing media 0 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Media 0 reset [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20001: Method is INVITE [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: 20001 [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: 20001 [Aug 18 12:14:10] DEBUG[1898] channel_internal_api.c: : Formats: (none) [Aug 18 12:14:10] DEBUG[1898] channel_internal_api.c: Channel is being initialized or destroyed [Aug 18 12:14:10] DEBUG[1898] stasis.c: Creating topic. name: channel:1629256450.3, detail: [Aug 18 12:14:10] DEBUG[1898] stasis.c: Topic 'channel:1629256450.3': 0x7f6c940303d0 created [Aug 18 12:14:10] DEBUG[742] threadpool.c: Increasing threadpool stasis/pool's size by 1 [Aug 18 12:14:10] DEBUG[1898] channel.c: Channel 0x7f6c9402ee70 'PJSIP/20001-00000002' allocated [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: Topology: <0:audio-0:audio:sendrecv (ulaw)> Formats: (ulaw) [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: Compatible? yes [Aug 18 12:14:10] DEBUG[1898] channel_internal_api.c: PJSIP/20001-00000002: MultistreamFormats: (ulaw) [Aug 18 12:14:10] DEBUG[1898] channel_internal_api.c: Set native formats but not topology [Aug 18 12:14:10] DEBUG[1898] channel_internal_api.c: PJSIP/20001-00000002: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:10] DEBUG[1898] channel_internal_api.c: Used provided topology [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/20001-00000002 [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: RC: 0 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Request: Session: PJSIP/20001-00000002 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: (null session) Handled request INVITE ? yes [Aug 18 12:14:10] DEBUG[1904][C-00000002] pbx.c: Launching 'Dial' [Aug 18 12:14:10] VERBOSE[1904][C-00000002] pbx.c: Executing [20002@from-internal:1] Dial("PJSIP/20001-00000002", "PJSIP/20002,90") in new stack [Aug 18 12:14:10] DEBUG[1904][C-00000002] app_dial.c: PJSIP/20001-00000002: Data: PJSIP/20002,90 [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: 20002 Topology: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: 20002 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: 20002 (null) Topology: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:10] DEBUG[1898] config.c: extract double from [3.0] in [-inf, inf] gives [3.000000](0) [Aug 18 12:14:10] DEBUG[1898] config.c: extract uint from [0] in [0, 4294967295] gives [0](0) [Aug 18 12:14:10] DEBUG[1898] config.c: extract double from [3.000000] in [-inf, inf] gives [3.000000](0) [Aug 18 12:14:10] DEBUG[1898] config.c: extract uint from [5060] in [0, 4294967295] gives [5060](0) [Aug 18 12:14:10] DEBUG[1898] config.c: extract uint from [0] in [0, 86400] gives [0](0) [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: 20002 [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: Direct media no glare mitigation [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session/pjsip_session_caps.c: '20002' Caps for outgoing audio call with pref 'remote_merge' - remote: (ulaw) local: (ulaw) joint: (ulaw) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: 20002 [Aug 18 12:14:10] DEBUG[1904][C-00000002] channel_internal_api.c: : Formats: (none) [Aug 18 12:14:10] DEBUG[1904][C-00000002] channel_internal_api.c: Channel is being initialized or destroyed [Aug 18 12:14:10] DEBUG[1904][C-00000002] stasis.c: Creating topic. name: channel:1629256450.4, detail: [Aug 18 12:14:10] DEBUG[1904][C-00000002] stasis.c: Topic 'channel:1629256450.4': 0x7f6c9c02acb0 created [Aug 18 12:14:10] DEBUG[1904][C-00000002] channel.c: Channel 0x7f6c9c00de70 'PJSIP/20002-00000003' allocated [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: Topology: <0:audio-0:audio:sendrecv (ulaw)> Formats: (ulaw) [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: Compatible? yes [Aug 18 12:14:10] DEBUG[1904][C-00000002] channel_internal_api.c: PJSIP/20002-00000003: MultistreamFormats: (ulaw) [Aug 18 12:14:10] DEBUG[1904][C-00000002] channel_internal_api.c: Set native formats but not topology [Aug 18 12:14:10] DEBUG[1904][C-00000002] channel_internal_api.c: PJSIP/20002-00000003: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:10] DEBUG[1904][C-00000002] channel_internal_api.c: Used provided topology [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: Channel: PJSIP/20002-00000003 [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 Topology: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003 Topology: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Processing streams [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Processing stream 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 Adding position 0 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Creating new media session [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Setting media session as default for audio [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Done [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 Stream: 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20002-00000003 Type: audio 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '0.0.0.0' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '0.0.0.0' and port ''. [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: Transport transport-udp bound to 0.0.0.0: Using it for RTP media. [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f6c9403bfc0' [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) RTP allocated port 19076 [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) ICE creating session 0.0.0.0:19076 (19076) [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) ICE create [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) ICE add system candidates [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting '192.168.10.125' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host '192.168.10.125' and port ''. [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) ICE add candidate: 192.168.10.125:19076, 2130706431 [Aug 18 12:14:10] DEBUG[1898] rtp_engine.c: RTP instance '0x7f6c9403bfc0' is setup and ready to go [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) ICE stopped [Aug 18 12:14:10] DEBUG[1898] netsock2.c: Splitting 'sipserver' into... [Aug 18 12:14:10] DEBUG[1898] netsock2.c: ...host 'sipserver' and port ''. [Aug 18 12:14:10] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) RTCP setup on RTP instance [Aug 18 12:14:10] DEBUG[1898] res_pjsip_sdp_rtp.c: RC: 1 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Handled [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Stream 0:audio-0:audio:sendrecv (ulaw) added [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Done with 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Adding bundle groups (if available) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Copying connection details [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Processing media 0 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Media 0 reset [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: 'call' task pushed [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Method is INVITE [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:10] DEBUG[1898] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.10.121' [Aug 18 12:14:10] DEBUG[1898] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.10.121' is 'UDP transport' [Aug 18 12:14:10] DEBUG[1898] res_pjsip/pjsip_resolver.c: Target '192.168.10.121' is an IP address, skipping resolution [Aug 18 12:14:10] DEBUG[1898] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to 192.168.10.125:5060 (this may be re-written again later) [Aug 18 12:14:10] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP request (918 bytes) to UDP:192.168.10.121:5060 ---> INVITE sip:20002@192.168.10.121:5060;ob SIP/2.0 Via: SIP/2.0/UDP 192.168.10.125:5060;rport;branch=z9hG4bKPj895d7e06-eaae-4594-aaa6-16b0c56ad42a From: ;tag=a35c2942-6408-42f6-a4c5-6fc2a502908b To: Contact: Call-ID: 1677c6e4-b608-4112-8800-2335fab7dafd CSeq: 12562 INVITE Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER Supported: 100rel, timer, replaces, norefersub, histinfo Session-Expires: 1800 Min-SE: 90 Max-Forwards: 70 User-Agent: Asterisk PBX 18.4.0 Content-Type: application/sdp Content-Length: 239 v=0 o=- 820822978 820822978 IN IP4 192.168.10.125 s=Asterisk c=IN IP4 192.168.10.125 t=0 0 m=audio 19076 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 Event: TSX_STATE Inv State: CALLING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20002(PJSIP/20002-00000003)' [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c9800c2e8) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: There is no transaction involved in this state change [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The current inv state is CALLING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Source of transaction state change is TX_MSG [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Calling Inv State: CALLING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20002(PJSIP/20002-00000003)' [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c9800c2e8) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f6c9800c2e8 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The current transaction state is Calling [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The current inv state is CALLING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Calling Inv State: CALLING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw)> Active: (null topology) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: RC: 0 [Aug 18 12:14:10] VERBOSE[1904][C-00000002] app_dial.c: Called PJSIP/20002 [Aug 18 12:14:10] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP response (345 bytes) from UDP:192.168.10.121:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.10.125:5060;rport=5060;received=192.168.10.125;branch=z9hG4bKPj895d7e06-eaae-4594-aaa6-16b0c56ad42a Call-ID: 1677c6e4-b608-4112-8800-2335fab7dafd From: ;tag=a35c2942-6408-42f6-a4c5-6fc2a502908b To: CSeq: 12562 INVITE Content-Length: 0 [Aug 18 12:14:10] DEBUG[833] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f6c980389a8 for Response msg 100/INVITE/cseq=12562 (rdata0x7f6c8c003458) [Aug 18 12:14:10] DEBUG[833] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/20002-0000005e associated with dialog dlg0x7f6c980389a8 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 Method: INVITE Status: 100 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Proceeding Inv State: CALLING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20002(PJSIP/20002-00000003)' [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c9800c2e8) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f6c9800c2e8 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The current transaction state is Proceeding [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The transaction state change event is RX_MSG [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: The current inv state is CALLING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Response is 100 Trying [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003: Status: 100 [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003: Not queueing anything [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003: Status: 100 [Aug 18 12:14:10] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Proceeding Inv State: CALLING [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw)> Active: (null topology) [Aug 18 12:14:10] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:10] DEBUG[1904][C-00000002] app_dial.c: PJSIP/20001-00000002 [Aug 18 12:14:10] DEBUG[1904][C-00000002] channel.c: Channel PJSIP/20002-00000003 setting read format path: ulaw -> ulaw [Aug 18 12:14:10] DEBUG[1904][C-00000002] channel.c: Channel PJSIP/20001-00000002 setting write format path: ulaw -> ulaw [Aug 18 12:14:10] DEBUG[1904][C-00000002] channel.c: Channel PJSIP/20001-00000002 setting read format path: ulaw -> ulaw [Aug 18 12:14:10] DEBUG[1904][C-00000002] channel.c: Channel PJSIP/20002-00000003 setting write format path: ulaw -> ulaw [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002: Indicated Connected line update [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002: Indicated Private Cause Code [Aug 18 12:14:10] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:14] DEBUG[845] res_pjsip_registrar.c: Woke up at 1629256454 Interval: 30 [Aug 18 12:14:14] DEBUG[845] res_pjsip_registrar.c: Expiring 0 contacts [Aug 18 12:14:21] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP response (983 bytes) from UDP:192.168.10.121:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.125:5060;rport=5060;received=192.168.10.125;branch=z9hG4bKPj895d7e06-eaae-4594-aaa6-16b0c56ad42a Call-ID: 1677c6e4-b608-4112-8800-2335fab7dafd From: ;tag=a35c2942-6408-42f6-a4c5-6fc2a502908b To: ;tag=15e8b258-93aa-41ea-b00c-0959522001bf CSeq: 12562 INVITE Contact: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800;refresher=uac Require: timer Content-Type: application/sdp Content-Length: 323 v=0 o=- 3838245250 3838245251 IN IP4 192.168.10.121 s=pjmedia b=AS:117 t=0 0 a=X-nat:0 m=audio 4002 RTP/AVP 0 101 c=IN IP4 192.168.10.121 b=TIAS:96000 a=rtcp:4003 IN IP4 192.168.10.121 a=sendrecv a=rtpmap:0 PCMU/8000 a=ssrc:1907530851 cname:0bdb83c25f81dfdc a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 [Aug 18 12:14:21] DEBUG[833] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f6c980389a8 for Response msg 200/INVITE/cseq=12562 (rdata0x7f6c8c003458) [Aug 18 12:14:21] DEBUG[833] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/20002-0000005e associated with dialog dlg0x7f6c980389a8 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 Method: INVITE Status: 200 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 Event: TSX_STATE Inv State: CONNECTING [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20002(PJSIP/20002-00000003)' [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c9800c2e8) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: There is no transaction involved in this state change [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current inv state is CONNECTING [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Source of transaction state change is RX_MSG [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Received response [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Response is 200 OK [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003: Status: 200 [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Applying negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20002-00000003 Stream: 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) RTCP ignoring duplicate property [Aug 18 12:14:21] DEBUG[1898] netsock2.c: Splitting '192.168.10.121' into... [Aug 18 12:14:21] DEBUG[1898] netsock2.c: ...host '192.168.10.121' and port ''. [Aug 18 12:14:21] DEBUG[1898] acl.c: For destination '192.168.10.121', our source address is '192.168.10.125'. [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) RTCP setting address on RTP instance [Aug 18 12:14:21] VERBOSE[1898] res_rtp_asterisk.c: 0x7f6c9403cf70 -- Strict RTP learning after remote address set to: 192.168.10.121:4002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20002-00000003 ANSWER [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f6c7dc73f70 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 0 (0x7f6c940600d8) from 0x7f6c7dc73f70 to 0x7f6c9403c198 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 101 (0x7f6c94060128) from 0x7f6c7dc73f70 to 0x7f6c9403c198 [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: PJSIP/20002-00000003: MultistreamFormats: (ulaw) [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: Set native formats but not topology [Aug 18 12:14:21] DEBUG[1898] channel.c: Channel PJSIP/20002-00000003 setting read format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1898] channel.c: Channel PJSIP/20002-00000003 setting write format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) DTLS - ast_rtp_activate rtp=0x7f6c9403cf70 - setup and perform DTLS' [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403cf70) DTLS perform handshake - ssl = (nil), setup = 0 [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403cf70) DTLS perform handshake - ssl = (nil), setup = 0 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: Handled [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Applied negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Applied negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: PJSIP/20002-00000003: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: Used provided topology [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.10.121' [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.10.121' is 'UDP transport' [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Target '192.168.10.121' is an IP address, skipping resolution [Aug 18 12:14:21] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP request (431 bytes) to UDP:192.168.10.121:5060 ---> ACK sip:20002@192.168.10.121:5060;ob SIP/2.0 Via: SIP/2.0/UDP 192.168.10.125:5060;rport;branch=z9hG4bKPjae5cbf78-3d79-4adb-8f7a-2f1a9d3d0cb2 From: ;tag=a35c2942-6408-42f6-a4c5-6fc2a502908b To: ;tag=15e8b258-93aa-41ea-b00c-0959522001bf Call-ID: 1677c6e4-b608-4112-8800-2335fab7dafd CSeq: 12562 ACK Max-Forwards: 70 User-Agent: Asterisk PBX 18.4.0 Content-Length: 0 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 Event: TX_MSG Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_state_changed called on event TX_MSG [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20002(PJSIP/20002-00000003)' [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c9800c2e8) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: There is no transaction involved in this state change [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Terminated Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20002(PJSIP/20002-00000003)' [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f6c9800c2e8 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current transaction state is Terminated [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The transaction state change event is RX_MSG [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Response is 200 OK [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003: Status: 200 [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003: Queueing ANSWER [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003: Status: 200 [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Terminated Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002: Indicated Private Cause Code [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1904][C-00000002] app_dial.c: PJSIP/20002-00000003 answered PJSIP/20001-00000002 [Aug 18 12:14:21] VERBOSE[1904][C-00000002] app_dial.c: PJSIP/20002-00000003 answered PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1904][C-00000002] app_dial.c: PJSIP/20001-00000002: Answered by PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1904][C-00000002] channel.c: Channel PJSIP/20002-00000003 setting read format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1904][C-00000002] channel.c: Channel PJSIP/20001-00000002 setting write format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1904][C-00000002] channel.c: Channel PJSIP/20001-00000002 setting read format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1904][C-00000002] channel.c: Channel PJSIP/20002-00000003 setting write format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[742] threadpool.c: Increasing threadpool stasis/pool's size by 1 [Aug 18 12:14:21] DEBUG[754] devicestate.c: No provider found, checking channel drivers for PJSIP - 20002 [Aug 18 12:14:21] DEBUG[754] devicestate.c: Changing state for PJSIP/20002 - state 2 (In use) [Aug 18 12:14:21] DEBUG[754] devicestate.c: No provider found, checking channel drivers for PJSIP - 20001 [Aug 18 12:14:21] DEBUG[754] devicestate.c: Changing state for PJSIP/20001 - state 2 (In use) [Aug 18 12:14:21] DEBUG[888] app_queue.c: Device 'PJSIP/20002' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Aug 18 12:14:21] DEBUG[888] app_queue.c: Device 'PJSIP/20001' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Applying negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20001-00000002 Stream: 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) RTCP ignoring duplicate property [Aug 18 12:14:21] DEBUG[1898] netsock2.c: Splitting '192.168.10.120' into... [Aug 18 12:14:21] DEBUG[1898] netsock2.c: ...host '192.168.10.120' and port ''. [Aug 18 12:14:21] DEBUG[1898] acl.c: For destination '192.168.10.120', our source address is '192.168.10.125'. [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) RTCP setting address on RTP instance [Aug 18 12:14:21] VERBOSE[1898] res_rtp_asterisk.c: 0x7f6c94027810 -- Strict RTP learning after remote address set to: 192.168.10.120:4002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20001-00000002 ANSWER [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f6c7dc74170 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Setting tx payload type 3 based on m type on 0x7f6c7dc74170 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f6c7dc74170 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Setting tx payload type 9 based on m type on 0x7f6c7dc74170 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 0 (0x7f6c94035e78) from 0x7f6c7dc74170 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 3 (0x7f6c94035518) from 0x7f6c7dc74170 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 8 (0x7f6c94061bd8) from 0x7f6c7dc74170 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 9 (0x7f6c94062008) from 0x7f6c7dc74170 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 96 (0x7f6c94044508) from 0x7f6c7dc74170 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 97 (0x7f6c94040658) from 0x7f6c7dc74170 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 98 (0x7f6c94041f08) from 0x7f6c7dc74170 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 99 (0x7f6c940406a8) from 0x7f6c7dc74170 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 102 (0x7f6c94062258) from 0x7f6c7dc74170 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 120 (0x7f6c940621b8) from 0x7f6c7dc74170 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: PJSIP/20001-00000002: MultistreamFormats: (ulaw) [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: Set native formats but not topology [Aug 18 12:14:21] DEBUG[1898] channel.c: Channel PJSIP/20001-00000002 setting read format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1898] channel.c: Channel PJSIP/20001-00000002 setting write format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) DTLS - ast_rtp_activate rtp=0x7f6c94027810 - setup and perform DTLS' [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94027810) DTLS perform handshake - ssl = (nil), setup = 0 [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94027810) DTLS perform handshake - ssl = (nil), setup = 0 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: Handled [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Applied negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Applied negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: PJSIP/20001-00000002: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: Used provided topology [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Method is INVITE, Response is 200 OK [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to 192.168.10.125:5060 (this may be re-written again later) [Aug 18 12:14:21] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP response (931 bytes) to UDP:192.168.10.120:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.120:5060;rport=5060;received=192.168.10.120;branch=z9hG4bKPj2d4808f6-4ea6-418e-b05c-81bf1b4a4d61 Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e From: ;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 To: ;tag=3655a7b6-5c61-4404-acb0-5d89b3d22674 CSeq: 16572 INVITE Server: Asterisk PBX 18.4.0 Contact: Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER Supported: 100rel, timer, replaces, norefersub Session-Expires: 1800;refresher=uac Require: timer Content-Type: application/sdp Content-Length: 241 v=0 o=- 3838245250 3838245252 IN IP4 192.168.10.125 s=Asterisk c=IN IP4 192.168.10.125 t=0 0 m=audio 14920 RTP/AVP 0 120 a=rtpmap:0 PCMU/8000 a=rtpmap:120 telephone-event/8000 a=fmtp:120 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 Event: TSX_STATE Inv State: CONNECTING [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001(PJSIP/20001-00000002)' [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c98036468) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: There is no transaction involved in this state change [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current inv state is CONNECTING [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Source of transaction state change is TX_MSG [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 TSX State: Completed Inv State: CONNECTING [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001(PJSIP/20001-00000002)' [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c98036468) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f6c98036468 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current transaction state is Completed [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current inv state is CONNECTING [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 TSX State: Completed Inv State: CONNECTING [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002: Indicated Stop generators [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis.c: Creating topic. name: bridge:all/bridge:59f5fe13-684e-4c91-9532-3ecb3347358a, detail: [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis.c: Topic 'bridge:all/bridge:59f5fe13-684e-4c91-9532-3ecb3347358a': 0x7f6c9c006f50 created [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a' can not use native RTP bridge as two channels are required [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Chose bridge technology simple_bridge [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: calling simple_bridge technology constructor [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: calling simple_bridge technology start [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c012988 Old: New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c012988 Old: New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge_channel.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: 0x7f6c9c0138d0(PJSIP/20002-00000003) is joining [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge_channel.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: pushing 0x7f6c9c0138d0(PJSIP/20002-00000003) [Aug 18 12:14:21] VERBOSE[1906][C-00000002] bridge_channel.c: Channel PJSIP/20002-00000003 joined 'simple_bridge' basic-bridge <59f5fe13-684e-4c91-9532-3ecb3347358a> [Aug 18 12:14:21] DEBUG[1906][C-00000002] stasis_bridges.c: Update: 0x7f6ca0003788 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1906][C-00000002] stasis_bridges.c: Update: 0x7f6ca0003788 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a' can not use native RTP bridge as two channels are required [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Chose bridge technology simple_bridge [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a is already using the new technology. [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: 0x7f6c9c0138d0(PJSIP/20002-00000003) is joining simple_bridge technology [Aug 18 12:14:21] DEBUG[1906][C-00000002] stasis_bridges.c: Update: 0x7f6ca0003b18 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1906][C-00000002] stasis_bridges.c: Update: 0x7f6ca0003b18 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_channel.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: 0x7f6c9c006ab0(PJSIP/20001-00000002) is joining [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_channel.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: pushing 0x7f6c9c006ab0(PJSIP/20001-00000002) [Aug 18 12:14:21] VERBOSE[1904][C-00000002] bridge_channel.c: Channel PJSIP/20001-00000002 joined 'simple_bridge' basic-bridge <59f5fe13-684e-4c91-9532-3ecb3347358a> [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c008798 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c008798 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Checking compatability for channels 'PJSIP/20002-00000003' and 'PJSIP/20001-00000002' [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Symmetric ptimes on the two call legs (0). May be able to native bridge in RTP [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a': Packetization comparison success between RTP streams (read_ptime0:20 == write_ptime1:20 and read_ptime1:20 == write_ptime0:20). [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Chose bridge technology native_rtp [Aug 18 12:14:21] VERBOSE[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: switching from simple_bridge technology to native_rtp [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: calling native_rtp technology constructor [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: moving 0x7f6c9c0138d0(PJSIP/20002-00000003) to dummy bridge temporarily [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: 0x7f6c9c0138d0(PJSIP/20002-00000003) is leaving simple_bridge technology (dummy) [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: calling simple_bridge technology stop [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: 0x7f6c9c006ab0(PJSIP/20001-00000002) is joining native_rtp technology [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Channel 'PJSIP/20001-00000002' is joining bridge tech [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Attaching hook data 0x7f6c9c0105b0 to 'PJSIP/20001-00000002' [Aug 18 12:14:21] DEBUG[1904][C-00000002] channel.c: PJSIP/20002-00000003: Topologies already match. Current: <0:audio-0:audio:sendrecv (ulaw)> Requested: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1904][C-00000002] channel.c: PJSIP/20002-00000003: Topologies already match. Current: <0:audio-0:audio:sendrecv (ulaw)> Requested: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: 0x7f6c9c0138d0(PJSIP/20002-00000003) is joining native_rtp technology [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Channel 'PJSIP/20002-00000003' is joining bridge tech [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Attaching hook data 0x7f6c9c026940 to 'PJSIP/20002-00000003' [Aug 18 12:14:21] DEBUG[1904][C-00000002] channel.c: PJSIP/20002-00000003: Topologies already match. Current: <0:audio-0:audio:sendrecv (ulaw)> Requested: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Tech starting 'PJSIP/20001-00000002' and 'PJSIP/20002-00000003' with target 'none' [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 (ulaw) [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 (ulaw) [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] VERBOSE[1904][C-00000002] bridge_native_rtp.c: Remotely bridged 'PJSIP/20001-00000002' and 'PJSIP/20002-00000003' - media will flow directly between them [Aug 18 12:14:21] DEBUG[1904][C-00000002] channel.c: PJSIP/20001-00000002: Topologies already match. Current: <0:audio-0:audio:sendrecv (ulaw)> Requested: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: calling native_rtp technology start [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: calling simple_bridge technology destructor [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c0193a8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c0193a8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002: Indicated Media SSRC change [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Checking compatability for channels 'PJSIP/20001-00000002' and 'PJSIP/20002-00000003' [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Symmetric ptimes on the two call legs (0). May be able to native bridge in RTP [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a': Packetization comparison success between RTP streams (read_ptime0:20 == write_ptime1:20 and read_ptime1:20 == write_ptime0:20). [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Chose bridge technology native_rtp [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a is already using the new technology. [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c01e5e8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c01e5e8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1904][C-00000002] res_rtp_asterisk.c: (0x7f6c94026c70) RTCP got report of 60 bytes from 192.168.10.120:4003 [Aug 18 12:14:21] DEBUG[1904][C-00000002] res_rtp_asterisk.c: (0x7f6c94026c70) RTCP got report of 60 bytes from 192.168.10.120:4003 [Aug 18 12:14:21] DEBUG[828] cdr.c: Finalized CDR for PJSIP/20002-00000003 - start 1629256450.532867 answer 1629256461.795397 end 1629256461.799266 dur 11.266 bill 0.003 dispo ANSWERED [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) DTLS srtp - stopped timeout timer' [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: RTP changed on PJSIP/20001-00000002; initiating direct media update [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: New SDP? yes Queued? no DP: none DA: none [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Delay sending reinvite because of outstanding transaction [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) DTLS srtp - stopped timeout timer' [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: RTP changed on PJSIP/20002-00000003; initiating direct media update [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: New SDP? yes Queued? no DP: none DA: none [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Processing streams [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Processing stream 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 Adding position 0 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Reusing existing media session [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Setting media session as default for audio [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Done [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 Stream: 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20002-00000003 Type: audio 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] acl.c: Attached to given IP address [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) RTCP setup on RTP instance [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: RC: 1 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Had handler [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Stream 0:audio-0:audio:sendrecv (ulaw) added [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Done with 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Adding bundle groups (if available) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Copying connection details [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Processing media 0 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Media 0 reset [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Method is INVITE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.10.121' [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.10.121' is 'UDP transport' [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Target '192.168.10.121' is an IP address, skipping resolution [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to 192.168.10.125:5060 (this may be re-written again later) [Aug 18 12:14:21] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP request (972 bytes) to UDP:192.168.10.121:5060 ---> INVITE sip:20002@192.168.10.121:5060;ob SIP/2.0 Via: SIP/2.0/UDP 192.168.10.125:5060;rport;branch=z9hG4bKPj46112cef-66b4-4d02-b385-617c6c5dc447 From: ;tag=a35c2942-6408-42f6-a4c5-6fc2a502908b To: ;tag=15e8b258-93aa-41ea-b00c-0959522001bf Contact: Call-ID: 1677c6e4-b608-4112-8800-2335fab7dafd CSeq: 12563 INVITE Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER Supported: 100rel, timer, replaces, norefersub, histinfo Session-Expires: 1800;refresher=uac Min-SE: 90 Max-Forwards: 70 User-Agent: Asterisk PBX 18.4.0 Content-Type: application/sdp Content-Length: 238 v=0 o=- 820822978 820822979 IN IP4 192.168.10.125 s=Asterisk c=IN IP4 192.168.10.120 t=0 0 m=audio 4002 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Calling Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20002(PJSIP/20002-00000003)' [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c98091ad8) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f6c98091ad8 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current transaction state is Calling [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Calling Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw)> Active: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Sending session refresh SDP via re-INVITE [Aug 18 12:14:21] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP request (382 bytes) from UDP:192.168.10.120:5060 ---> ACK sip:192.168.10.125:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.120:5060;rport;branch=z9hG4bKPj609ebde2-fca0-4e8f-951d-f5fd030619ce Max-Forwards: 70 From: sip:20001@192.168.10.120;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 To: sip:20002@192.168.10.125;tag=3655a7b6-5c61-4404-acb0-5d89b3d22674 Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e CSeq: 16572 ACK Content-Length: 0 [Aug 18 12:14:21] DEBUG[833] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f6c9803a628 for Request msg ACK/cseq=16572 (rdata0x7f6c8c003458) [Aug 18 12:14:21] DEBUG[833] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000038 associated with dialog dlg0x7f6c9803a628 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 TSX State: Terminated Inv State: CONNECTING [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001(PJSIP/20001-00000002)' [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f6c98036468 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current transaction state is Terminated [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The transaction state change event is USER [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current inv state is CONNECTING [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: INVITE delay check. tsx-state:Terminated [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 TSX State: Terminated Inv State: CONNECTING [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 Event: RX_MSG Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_state_changed called on event RX_MSG [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001(PJSIP/20001-00000002)' [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: There is no transaction involved in this state change [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Received request [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Method is ACK [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20001-00000002: Queueing SRCCHANGE [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 Request: ACK [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 Handled request ACK ? yes [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Sending delayed INVITE request [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: sending delayed INVITE request [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: New SDP? yes Queued? yes DP: none DA: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Processing streams [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Processing stream 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 Adding position 0 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Reusing existing media session [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Setting media session as default for audio [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Done [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 Stream: 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20001-00000002 Type: audio 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] acl.c: Attached to given IP address [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) RTCP failed to setup RTP instance [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: RC: 1 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Had handler [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Stream 0:audio-0:audio:sendrecv (ulaw) added [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Done with 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Adding bundle groups (if available) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Copying connection details [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Processing media 0 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Media 0 reset [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Method is INVITE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.10.120' [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.10.120' is 'UDP transport' [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Target '192.168.10.120' is an IP address, skipping resolution [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to 192.168.10.125:5060 (this may be re-written again later) [Aug 18 12:14:21] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP request (962 bytes) to UDP:192.168.10.120:5060 ---> INVITE sip:20001@192.168.10.120:5060;ob SIP/2.0 Via: SIP/2.0/UDP 192.168.10.125:5060;rport;branch=z9hG4bKPj179ac033-0be2-41bd-bcd9-0ab38f2357f5 From: ;tag=3655a7b6-5c61-4404-acb0-5d89b3d22674 To: ;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 Contact: Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e CSeq: 23984 INVITE Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER Supported: 100rel, timer, replaces, norefersub, histinfo Session-Expires: 1800;refresher=uas Min-SE: 90 Max-Forwards: 70 User-Agent: Asterisk PBX 18.4.0 Content-Type: application/sdp Content-Length: 240 v=0 o=- 3838245250 3838245253 IN IP4 192.168.10.125 s=Asterisk c=IN IP4 192.168.10.121 t=0 0 m=audio 4002 RTP/AVP 0 120 a=rtpmap:0 PCMU/8000 a=rtpmap:120 telephone-event/8000 a=fmtp:120 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 TSX State: Calling Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001(PJSIP/20001-00000002)' [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c9800c2e8) [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f6c9800c2e8 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current transaction state is Calling [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 TSX State: Calling Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw)> Active: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Sending session refresh SDP via re-INVITE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20002-00000003: Indicated Media SSRC change [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Checking compatability for channels 'PJSIP/20001-00000002' and 'PJSIP/20002-00000003' [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge_native_rtp.c: Symmetric ptimes on the two call legs (0). May be able to native bridge in RTP [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a': Packetization comparison success between RTP streams (read_ptime0:20 == write_ptime1:20 and read_ptime1:20 == write_ptime0:20). [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Chose bridge technology native_rtp [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a is already using the new technology. [Aug 18 12:14:21] DEBUG[1906][C-00000002] stasis_bridges.c: Update: 0x7f6ca00076b8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1906][C-00000002] stasis_bridges.c: Update: 0x7f6ca00076b8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20002-00000003: Indicated Media SSRC change [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002: Indicated Private Cause Code [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:21] VERBOSE[1906][C-00000002] res_rtp_asterisk.c: 0x7f6c9403cf70 -- Strict RTP switching to RTP target address 192.168.10.121:4002 as source [Aug 18 12:14:21] DEBUG[1904][C-00000002] res_rtp_asterisk.c: (0x7f6c94026c70) RTP ooh, format changed from none to ulaw [Aug 18 12:14:21] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP response (964 bytes) from UDP:192.168.10.120:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.125:5060;rport=5060;received=192.168.10.125;branch=z9hG4bKPj179ac033-0be2-41bd-bcd9-0ab38f2357f5 Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e From: ;tag=3655a7b6-5c61-4404-acb0-5d89b3d22674 To: ;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 CSeq: 23984 INVITE Session-Expires: 1800;refresher=uas Contact: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Content-Type: application/sdp Content-Length: 323 v=0 o=- 3838245250 3838245251 IN IP4 192.168.10.120 s=pjmedia b=AS:117 t=0 0 a=X-nat:0 m=audio 4002 RTP/AVP 0 120 c=IN IP4 192.168.10.120 b=TIAS:96000 a=rtcp:4003 IN IP4 192.168.10.120 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:120 telephone-event/8000 a=fmtp:120 0-16 a=ssrc:2046365698 cname:3193f1c15cf5d1ec [Aug 18 12:14:21] DEBUG[833] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f6c9803a628 for Response msg 200/INVITE/cseq=23984 (rdata0x7f6c8c003458) [Aug 18 12:14:21] DEBUG[833] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000038 associated with dialog dlg0x7f6c9803a628 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 Method: INVITE Status: 200 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Applying negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20001-00000002 Stream: 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] acl.c: Attached to given IP address [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) RTCP setup on RTP instance [Aug 18 12:14:21] DEBUG[1898] netsock2.c: Splitting '192.168.10.120' into... [Aug 18 12:14:21] DEBUG[1898] netsock2.c: ...host '192.168.10.120' and port ''. [Aug 18 12:14:21] DEBUG[1898] acl.c: For destination '192.168.10.120', our source address is '192.168.10.125'. [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) RTCP setting address on RTP instance [Aug 18 12:14:21] VERBOSE[1898] res_rtp_asterisk.c: 0x7f6c94027810 -- Strict RTP learning after remote address set to: 192.168.10.120:4002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20001-00000002 ANSWER [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f6c7dc73f30 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 0 (0x7f6c94040b58) from 0x7f6c7dc73f30 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 120 (0x7f6c94032f68) from 0x7f6c7dc73f30 to 0x7f6c94026e48 [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: PJSIP/20001-00000002: MultistreamFormats: (ulaw) [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: Set native formats but not topology [Aug 18 12:14:21] DEBUG[1898] channel.c: Channel PJSIP/20001-00000002 setting read format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1898] channel.c: Channel PJSIP/20001-00000002 setting write format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) DTLS - ast_rtp_activate rtp=0x7f6c94027810 - setup and perform DTLS' [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94027810) DTLS perform handshake - ssl = (nil), setup = 0 [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94027810) DTLS perform handshake - ssl = (nil), setup = 0 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: Handled [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Applied negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Applied negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: PJSIP/20001-00000002: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: Used provided topology [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.10.120' [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.10.120' is 'UDP transport' [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Target '192.168.10.120' is an IP address, skipping resolution [Aug 18 12:14:21] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP request (428 bytes) to UDP:192.168.10.120:5060 ---> ACK sip:20001@192.168.10.120:5060;ob SIP/2.0 Via: SIP/2.0/UDP 192.168.10.125:5060;rport;branch=z9hG4bKPj2ec6ee0b-fc6f-4940-bce2-e4d24ef5be35 From: ;tag=3655a7b6-5c61-4404-acb0-5d89b3d22674 To: ;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e CSeq: 23984 ACK Max-Forwards: 70 User-Agent: Asterisk PBX 18.4.0 Content-Length: 0 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 TSX State: Terminated Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001(PJSIP/20001-00000002)' [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f6c9800c2e8 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current transaction state is Terminated [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The transaction state change event is RX_MSG [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002: Response is 200 OK [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20001-00000002: Status: 200 [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20001-00000002: Queueing ANSWER [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20001-00000002: Status: 200 [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20001-00000002 TSX State: Terminated Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Checking compatability for channels 'PJSIP/20001-00000002' and 'PJSIP/20002-00000003' [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Symmetric ptimes on the two call legs (0). May be able to native bridge in RTP [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a': Packetization comparison success between RTP streams (read_ptime0:20 == write_ptime1:20 and read_ptime1:20 == write_ptime0:20). [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Chose bridge technology native_rtp [Aug 18 12:14:21] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a is already using the new technology. [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c0173a8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c0173a8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1904][C-00000002] channel.c: Dropping duplicate answer! [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20002-00000003: Indicated Private Cause Code [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:21] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP response (983 bytes) from UDP:192.168.10.121:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.125:5060;rport=5060;received=192.168.10.125;branch=z9hG4bKPj46112cef-66b4-4d02-b385-617c6c5dc447 Call-ID: 1677c6e4-b608-4112-8800-2335fab7dafd From: ;tag=a35c2942-6408-42f6-a4c5-6fc2a502908b To: ;tag=15e8b258-93aa-41ea-b00c-0959522001bf CSeq: 12563 INVITE Session-Expires: 1800;refresher=uac Require: timer Contact: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Content-Type: application/sdp Content-Length: 323 v=0 o=- 3838245250 3838245252 IN IP4 192.168.10.121 s=pjmedia b=AS:117 t=0 0 a=X-nat:0 m=audio 4002 RTP/AVP 0 101 c=IN IP4 192.168.10.121 b=TIAS:96000 a=rtcp:4003 IN IP4 192.168.10.121 a=sendrecv a=rtpmap:0 PCMU/8000 a=ssrc:1907530851 cname:0bdb83c25f81dfdc a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 [Aug 18 12:14:21] DEBUG[833] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f6c980389a8 for Response msg 200/INVITE/cseq=12563 (rdata0x7f6c8c003458) [Aug 18 12:14:21] DEBUG[833] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/20002-0000005e associated with dialog dlg0x7f6c980389a8 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 Method: INVITE Status: 200 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Applying negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20002-00000003 Stream: 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) RTCP ignoring duplicate property [Aug 18 12:14:21] DEBUG[1898] netsock2.c: Splitting '192.168.10.121' into... [Aug 18 12:14:21] DEBUG[1898] netsock2.c: ...host '192.168.10.121' and port ''. [Aug 18 12:14:21] DEBUG[1898] acl.c: For destination '192.168.10.121', our source address is '192.168.10.125'. [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) RTCP setting address on RTP instance [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20002-00000003 ANSWER [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f6c7dc73f30 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 0 (0x7f6c940266f8) from 0x7f6c7dc73f30 to 0x7f6c9403c198 [Aug 18 12:14:21] DEBUG[1898] rtp_engine.c: Copying tx payload mapping 101 (0x7f6c94015a48) from 0x7f6c7dc73f30 to 0x7f6c9403c198 [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: PJSIP/20002-00000003: MultistreamFormats: (ulaw) [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: Set native formats but not topology [Aug 18 12:14:21] DEBUG[1898] channel.c: Channel PJSIP/20002-00000003 setting read format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1898] channel.c: Channel PJSIP/20002-00000003 setting write format path: ulaw -> ulaw [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403bfc0) DTLS - ast_rtp_activate rtp=0x7f6c9403cf70 - setup and perform DTLS' [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403cf70) DTLS perform handshake - ssl = (nil), setup = 0 [Aug 18 12:14:21] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c9403cf70) DTLS perform handshake - ssl = (nil), setup = 0 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_sdp_rtp.c: Handled [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Applied negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Applied negotiated SDP media stream 'audio' using audio SDP handler [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: PJSIP/20002-00000003: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] channel_internal_api.c: Used provided topology [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.10.121' [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.10.121' is 'UDP transport' [Aug 18 12:14:21] DEBUG[1898] res_pjsip/pjsip_resolver.c: Target '192.168.10.121' is an IP address, skipping resolution [Aug 18 12:14:21] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP request (431 bytes) to UDP:192.168.10.121:5060 ---> ACK sip:20002@192.168.10.121:5060;ob SIP/2.0 Via: SIP/2.0/UDP 192.168.10.125:5060;rport;branch=z9hG4bKPj82eb6a1b-b540-46fb-91e0-995559f8a5fb From: ;tag=a35c2942-6408-42f6-a4c5-6fc2a502908b To: ;tag=15e8b258-93aa-41ea-b00c-0959522001bf Call-ID: 1677c6e4-b608-4112-8800-2335fab7dafd CSeq: 12563 ACK Max-Forwards: 70 User-Agent: Asterisk PBX 18.4.0 Content-Length: 0 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Terminated Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20002(PJSIP/20002-00000003)' [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f6c98091ad8 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current transaction state is Terminated [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The transaction state change event is RX_MSG [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Response is 200 OK [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003: Status: 200 [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003: Queueing ANSWER [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003: Status: 200 [Aug 18 12:14:21] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Terminated Inv State: CONFIRMED [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:21] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Checking compatability for channels 'PJSIP/20001-00000002' and 'PJSIP/20002-00000003' [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 Native formats (ulaw) [Aug 18 12:14:21] DEBUG[1906][C-00000002] chan_pjsip.c: [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge_native_rtp.c: Symmetric ptimes on the two call legs (0). May be able to native bridge in RTP [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a': Packetization comparison success between RTP streams (read_ptime0:20 == write_ptime1:20 and read_ptime1:20 == write_ptime0:20). [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Chose bridge technology native_rtp [Aug 18 12:14:21] DEBUG[1906][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a is already using the new technology. [Aug 18 12:14:21] DEBUG[1906][C-00000002] stasis_bridges.c: Update: 0x7f6ca00055e8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1906][C-00000002] stasis_bridges.c: Update: 0x7f6ca00055e8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:21] DEBUG[1906][C-00000002] channel.c: Dropping duplicate answer! [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002: Indicated Private Cause Code [Aug 18 12:14:21] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:21] DEBUG[1906][C-00000002] res_rtp_asterisk.c: (0x7f6c9403bfc0) RTCP got report of 88 bytes from 192.168.10.121:4003 [Aug 18 12:14:21] DEBUG[1906][C-00000002] res_rtp_asterisk.c: (0x7f6c9403bfc0) RTCP got report of 68 bytes from 192.168.10.121:4003 [Aug 18 12:14:37] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP request (459 bytes) from UDP:192.168.10.121:5060 ---> BYE sip:asterisk@192.168.10.125:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.10.121:5060;rport;branch=z9hG4bKPj366fb68c-ce08-425f-8a1d-ca9ec90beb6e Max-Forwards: 70 From: ;tag=15e8b258-93aa-41ea-b00c-0959522001bf To: ;tag=a35c2942-6408-42f6-a4c5-6fc2a502908b Call-ID: 1677c6e4-b608-4112-8800-2335fab7dafd CSeq: 27099 BYE User-Agent: PJSUA v2.9-svn Linux-5.8.0.63/x86_64/glibc-2.31 Content-Length: 0 [Aug 18 12:14:37] DEBUG[833] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f6c980389a8 for Request msg BYE/cseq=27099 (rdata0x7f6c8c003458) [Aug 18 12:14:37] DEBUG[833] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/20002-0000005e associated with dialog dlg0x7f6c980389a8 [Aug 18 12:14:37] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP response (408 bytes) to UDP:192.168.10.121:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.121:5060;rport=5060;received=192.168.10.121;branch=z9hG4bKPj366fb68c-ce08-425f-8a1d-ca9ec90beb6e Call-ID: 1677c6e4-b608-4112-8800-2335fab7dafd From: ;tag=15e8b258-93aa-41ea-b00c-0959522001bf To: ;tag=a35c2942-6408-42f6-a4c5-6fc2a502908b CSeq: 27099 BYE Server: Asterisk PBX 18.4.0 Content-Length: 0 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Completed Inv State: CONFIRMED [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20002(PJSIP/20002-00000003)' [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f6c98091ad8 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current transaction state is Completed [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Completed Inv State: CONFIRMED [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 Event: TSX_STATE Inv State: DISCONNCTD [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20002(PJSIP/20002-00000003)' [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: There is no transaction involved in this state change [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current inv state is DISCONNCTD [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Source of transaction state change is RX_MSG [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Received request [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003: Method is BYE [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Completed Inv State: DISCONNCTD [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20002(PJSIP/20002-00000003)' [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f6c98091ad8 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current transaction state is Completed [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The transaction state change event is RX_MSG [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current inv state is DISCONNCTD [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: PJSIP/20002-00000003 TSX State: Completed Inv State: DISCONNCTD [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1898] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:37] DEBUG[1898] chan_pjsip.c: [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge_channel.c: Setting 0x7f6c9c0138d0(PJSIP/20002-00000003) state from:0 to:1 [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge_channel.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: pulling 0x7f6c9c0138d0(PJSIP/20002-00000003) [Aug 18 12:14:37] VERBOSE[1906][C-00000002] bridge_channel.c: Channel PJSIP/20002-00000003 left 'native_rtp' basic-bridge <59f5fe13-684e-4c91-9532-3ecb3347358a> [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge_channel.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: 0x7f6c9c0138d0(PJSIP/20002-00000003) is leaving native_rtp technology [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Channel 'PJSIP/20002-00000003' is leaving bridge tech [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Detaching hook data 0x7f6c9c0279e8 from 'PJSIP/20002-00000003' [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Tech stopping 'PJSIP/20001-00000002' and 'PJSIP/20002-00000003' with target 'none' [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Bringing back 'PJSIP/20001-00000002' and 'PJSIP/20002-00000003' to us [Aug 18 12:14:37] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 (nothing) [Aug 18 12:14:37] DEBUG[1906][C-00000002] chan_pjsip.c: [Aug 18 12:14:37] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 (nothing) [Aug 18 12:14:37] DEBUG[1906][C-00000002] chan_pjsip.c: [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge_native_rtp.c: Discontinued RTP bridging of 'PJSIP/20001-00000002' and 'PJSIP/20002-00000003' - media will flow through Asterisk core [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge_native_rtp.c: Destroying channel tech_pvt data 0x7f6c9c026940 [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: dissolving bridge with cause 16(Normal Clearing) [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge_channel.c: Setting 0x7f6c9c006ab0(PJSIP/20001-00000002) state from:0 to:2 [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: queueing action type:13 sub:1001 [Aug 18 12:14:37] DEBUG[1906][C-00000002] stasis_bridges.c: Update: 0x7f6ca000c848 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:37] DEBUG[1906][C-00000002] stasis_bridges.c: Update: 0x7f6ca000c848 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:37] DEBUG[1906][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a is dissolved, not performing smart bridge operation. [Aug 18 12:14:37] DEBUG[1906][C-00000002] channel.c: Channel 0x7f6c9c00de70 'PJSIP/20002-00000003' hanging up. Refs: 3 [Aug 18 12:14:37] DEBUG[1906][C-00000002] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:37] DEBUG[1906][C-00000002] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Aug 18 12:14:37] DEBUG[1906][C-00000002] chan_pjsip.c: Cause: 0 [Aug 18 12:14:37] DEBUG[828] cdr.c: Finalized CDR for PJSIP/20001-00000002 - start 1629256450.531545 answer 1629256461.795484 end 1629256477.214393 dur 26.682 bill 15.418 dispo ANSWERED [Aug 18 12:14:37] DEBUG[1904][C-00000002] bridge_channel.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: pulling 0x7f6c9c006ab0(PJSIP/20001-00000002) [Aug 18 12:14:37] VERBOSE[1904][C-00000002] bridge_channel.c: Channel PJSIP/20001-00000002 left 'native_rtp' basic-bridge <59f5fe13-684e-4c91-9532-3ecb3347358a> [Aug 18 12:14:37] DEBUG[1904][C-00000002] bridge_channel.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: 0x7f6c9c006ab0(PJSIP/20001-00000002) is leaving native_rtp technology [Aug 18 12:14:37] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Channel 'PJSIP/20001-00000002' is leaving bridge tech [Aug 18 12:14:37] DEBUG[1904][C-00000002] bridge_native_rtp.c: Bridge '59f5fe13-684e-4c91-9532-3ecb3347358a'. Detaching hook data 0x7f6c9c00f838 from 'PJSIP/20001-00000002' [Aug 18 12:14:37] DEBUG[1904][C-00000002] bridge_native_rtp.c: Destroying channel tech_pvt data 0x7f6c9c0105b0 [Aug 18 12:14:37] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c017bf8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:37] DEBUG[1904][C-00000002] stasis_bridges.c: Update: 0x7f6c9c017bf8 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: 59f5fe13-684e-4c91-9532-3ecb3347358a [Aug 18 12:14:37] DEBUG[1904][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a is dissolved, not performing smart bridge operation. [Aug 18 12:14:37] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002: Indicated Media SSRC change [Aug 18 12:14:37] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:37] DEBUG[1904][C-00000002] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Aug 18 12:14:37] DEBUG[1904][C-00000002] app_dial.c: PJSIP/20001-00000002: Done [Aug 18 12:14:37] DEBUG[1904][C-00000002] pbx.c: Spawn extension (from-internal,20002,1) exited non-zero on 'PJSIP/20001-00000002' [Aug 18 12:14:37] VERBOSE[1904][C-00000002] pbx.c: Spawn extension (from-internal, 20002, 1) exited non-zero on 'PJSIP/20001-00000002' [Aug 18 12:14:37] DEBUG[1904][C-00000002] channel.c: Soft-Hanging (0x10) up channel 'PJSIP/20001-00000002' [Aug 18 12:14:37] DEBUG[1904][C-00000002] channel.c: Channel 0x7f6c9402ee70 'PJSIP/20001-00000002' hanging up. Refs: 3 [Aug 18 12:14:37] DEBUG[1904][C-00000002] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:37] DEBUG[1904][C-00000002] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Aug 18 12:14:37] DEBUG[1904][C-00000002] chan_pjsip.c: Cause: 0 [Aug 18 12:14:37] DEBUG[753][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: actually destroying basic bridge, nobody wants it anymore [Aug 18 12:14:37] DEBUG[753][C-00000002] stasis_bridges.c: Update: 0x7f6c94040758 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: [Aug 18 12:14:37] DEBUG[753][C-00000002] stasis_bridges.c: Update: 0x7f6c94040758 Old: 59f5fe13-684e-4c91-9532-3ecb3347358a New: [Aug 18 12:14:37] DEBUG[753][C-00000002] stasis.c: Destroying topic. name: bridge:all/bridge:59f5fe13-684e-4c91-9532-3ecb3347358a, detail: [Aug 18 12:14:37] DEBUG[753][C-00000002] stasis.c: Topic 'bridge:all/bridge:59f5fe13-684e-4c91-9532-3ecb3347358a': 0x7f6c9c006f50 destroyed [Aug 18 12:14:37] DEBUG[753][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: calling basic bridge destructor [Aug 18 12:14:37] DEBUG[753][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: calling native_rtp technology stop [Aug 18 12:14:37] DEBUG[753][C-00000002] bridge.c: Bridge 59f5fe13-684e-4c91-9532-3ecb3347358a: calling native_rtp technology destructor [Aug 18 12:14:37] DEBUG[1899] res_rtp_asterisk.c: (0x7f6c94026c70) RTCP ignoring duplicate property [Aug 18 12:14:37] DEBUG[1899] chan_pjsip.c: RTP changed on PJSIP/20001-00000002; initiating direct media update [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: New SDP? yes Queued? no DP: none DA: none [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: Processing streams [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: Processing stream 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002 Adding position 0 [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: Reusing existing media session [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: Setting media session as default for audio [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: Done [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002 Stream: 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:37] DEBUG[1899] res_pjsip_sdp_rtp.c: PJSIP/20001-00000002 Type: audio 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:37] DEBUG[1899] res_rtp_asterisk.c: (0x7f6c94026c70) RTCP ignoring duplicate property [Aug 18 12:14:37] DEBUG[1899] res_pjsip_sdp_rtp.c: RC: 1 [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: Had handler [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: Stream 0:audio-0:audio:sendrecv (ulaw) added [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: Done with 0:audio-0:audio:sendrecv (ulaw) [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: Adding bundle groups (if available) [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: Copying connection details [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: Processing media 0 [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: Media 0 reset [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: Method is INVITE [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:37] DEBUG[1899] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.10.120' [Aug 18 12:14:37] DEBUG[1899] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.10.120' is 'UDP transport' [Aug 18 12:14:37] DEBUG[1899] res_pjsip/pjsip_resolver.c: Target '192.168.10.120' is an IP address, skipping resolution [Aug 18 12:14:37] DEBUG[1899] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to 192.168.10.125:5060 (this may be re-written again later) [Aug 18 12:14:37] VERBOSE[1899] res_pjsip_logger.c: <--- Transmitting SIP request (963 bytes) to UDP:192.168.10.120:5060 ---> INVITE sip:20001@192.168.10.120:5060;ob SIP/2.0 Via: SIP/2.0/UDP 192.168.10.125:5060;rport;branch=z9hG4bKPjc46c6417-66a1-4d33-a3eb-5447d024aee1 From: ;tag=3655a7b6-5c61-4404-acb0-5d89b3d22674 To: ;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 Contact: Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e CSeq: 23985 INVITE Allow: OPTIONS, REGISTER, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, MESSAGE, REFER Supported: 100rel, timer, replaces, norefersub, histinfo Session-Expires: 1800;refresher=uas Min-SE: 90 Max-Forwards: 70 User-Agent: Asterisk PBX 18.4.0 Content-Type: application/sdp Content-Length: 241 v=0 o=- 3838245250 3838245254 IN IP4 192.168.10.125 s=Asterisk c=IN IP4 192.168.10.125 t=0 0 m=audio 14920 RTP/AVP 0 120 a=rtpmap:0 PCMU/8000 a=rtpmap:120 telephone-event/8000 a=fmtp:120 0-16 a=ptime:20 a=maxptime:150 a=sendrecv [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002 TSX State: Calling Inv State: CONFIRMED [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: The state change pertains to the endpoint '20001(PJSIP/20001-00000002)' [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f6c9800c2e8) [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f6c9800c2e8 [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: The current transaction state is Calling [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002 TSX State: Calling Inv State: CONFIRMED [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw)> Active: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: Sending session refresh SDP via re-INVITE [Aug 18 12:14:37] DEBUG[1899] chan_pjsip.c: PJSIP/20001-00000002 [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002 Response 0 [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002: Delay sending BYE because of outstanding transaction... [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20001-00000002 [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1899] channel.c: Channel 0x7f6c9402ee70 'PJSIP/20001-00000002' destroying [Aug 18 12:14:37] DEBUG[1899] stasis.c: Destroying topic. name: channel:1629256450.3, detail: [Aug 18 12:14:37] DEBUG[1899] stasis.c: Topic 'channel:1629256450.3': 0x7f6c940303d0 destroyed [Aug 18 12:14:37] DEBUG[1899] channel_internal_api.c: : MultistreamFormats: (nothing) [Aug 18 12:14:37] DEBUG[1899] channel_internal_api.c: Channel is being initialized or destroyed [Aug 18 12:14:37] DEBUG[1899] chan_pjsip.c: [Aug 18 12:14:37] DEBUG[1899] res_rtp_asterisk.c: (0x7f6c9403bfc0) RTCP ignoring duplicate property [Aug 18 12:14:37] DEBUG[1899] chan_pjsip.c: RTP changed on PJSIP/20002-00000003; initiating direct media update [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20002-00000003: New SDP? yes Queued? no DP: none DA: none [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20002-00000003: Not sending reinvite because of disconnected state [Aug 18 12:14:37] DEBUG[1899] chan_pjsip.c: PJSIP/20002-00000003 [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: PJSIP/20002-00000003 Response 0 [Aug 18 12:14:37] DEBUG[1899] res_rtp_asterisk.c: (0x7f6c9403bfc0) DTLS srtp - stopped timeout timer' [Aug 18 12:14:37] DEBUG[1899] res_rtp_asterisk.c: (0x7f6c9403bfc0) DTLS srtp - stopped timeout timer' [Aug 18 12:14:37] DEBUG[1899] res_rtp_asterisk.c: (0x7f6c9403bfc0) DTLS stop [Aug 18 12:14:37] DEBUG[1899] res_rtp_asterisk.c: (0x7f6c9403bfc0) DTLS srtp - stopped timeout timer' [Aug 18 12:14:37] DEBUG[1899] res_rtp_asterisk.c: (0x7f6c9403bfc0) DTLS srtp - stopped timeout timer' [Aug 18 12:14:37] DEBUG[1899] res_rtp_asterisk.c: (0x7f6c9403bfc0) ICE RTP transport deallocating [Aug 18 12:14:37] DEBUG[1899] rtp_engine.c: Destroyed RTP instance '0x7f6c9403bfc0' [Aug 18 12:14:37] DEBUG[1899] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1899] channel.c: Channel 0x7f6c9c00de70 'PJSIP/20002-00000003' destroying [Aug 18 12:14:37] DEBUG[1899] stasis.c: Destroying topic. name: channel:1629256450.4, detail: [Aug 18 12:14:37] DEBUG[1899] stasis.c: Topic 'channel:1629256450.4': 0x7f6c9c02acb0 destroyed [Aug 18 12:14:37] DEBUG[1899] channel_internal_api.c: : MultistreamFormats: (nothing) [Aug 18 12:14:37] DEBUG[1899] channel_internal_api.c: Channel is being initialized or destroyed [Aug 18 12:14:37] DEBUG[1899] chan_pjsip.c: [Aug 18 12:14:37] DEBUG[754] devicestate.c: No provider found, checking channel drivers for PJSIP - 20001 [Aug 18 12:14:37] DEBUG[754] devicestate.c: Changing state for PJSIP/20001 - state 1 (Not in use) [Aug 18 12:14:37] DEBUG[754] devicestate.c: No provider found, checking channel drivers for PJSIP - 20002 [Aug 18 12:14:37] DEBUG[754] devicestate.c: Changing state for PJSIP/20002 - state 1 (Not in use) [Aug 18 12:14:37] DEBUG[888] app_queue.c: Device 'PJSIP/20001' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 18 12:14:37] DEBUG[888] app_queue.c: Device 'PJSIP/20002' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 18 12:14:37] DEBUG[828] stasis.c: Creating topic. name: channel:1629256477.5, detail: [Aug 18 12:14:37] DEBUG[828] stasis.c: Topic 'channel:1629256477.5': 0x7f6c9405d260 created [Aug 18 12:14:37] DEBUG[828] stasis.c: Destroying topic. name: channel:1629256477.5, detail: [Aug 18 12:14:37] DEBUG[828] stasis.c: Topic 'channel:1629256477.5': 0x7f6c9405d260 destroyed [Aug 18 12:14:37] DEBUG[828] cdr.c: CDR for PJSIP/20002-00000003 is dialed and has no Party B; discarding [Aug 18 12:14:37] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP response (964 bytes) from UDP:192.168.10.120:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.125:5060;rport=5060;received=192.168.10.125;branch=z9hG4bKPjc46c6417-66a1-4d33-a3eb-5447d024aee1 Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e From: ;tag=3655a7b6-5c61-4404-acb0-5d89b3d22674 To: ;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 CSeq: 23985 INVITE Session-Expires: 1800;refresher=uas Contact: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Content-Type: application/sdp Content-Length: 323 v=0 o=- 3838245250 3838245252 IN IP4 192.168.10.120 s=pjmedia b=AS:117 t=0 0 a=X-nat:0 m=audio 4002 RTP/AVP 0 120 c=IN IP4 192.168.10.120 b=TIAS:96000 a=rtcp:4003 IN IP4 192.168.10.120 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:120 telephone-event/8000 a=fmtp:120 0-16 a=ssrc:2046365698 cname:3193f1c15cf5d1ec [Aug 18 12:14:37] DEBUG[833] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f6c9803a628 for Response msg 200/INVITE/cseq=23985 (rdata0x7f6c8c003458) [Aug 18 12:14:37] DEBUG[833] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000038 associated with dialog dlg0x7f6c9803a628 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 Method: INVITE Status: 200 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: No channel or session [Aug 18 12:14:37] DEBUG[1898] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.10.120' [Aug 18 12:14:37] DEBUG[1898] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.10.120' is 'UDP transport' [Aug 18 12:14:37] DEBUG[1898] res_pjsip/pjsip_resolver.c: Target '192.168.10.120' is an IP address, skipping resolution [Aug 18 12:14:37] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP request (428 bytes) to UDP:192.168.10.120:5060 ---> ACK sip:20001@192.168.10.120:5060;ob SIP/2.0 Via: SIP/2.0/UDP 192.168.10.125:5060;rport;branch=z9hG4bKPj34a1d0a4-bf7a-4e46-a2f2-79105659cde7 From: ;tag=3655a7b6-5c61-4404-acb0-5d89b3d22674 To: ;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e CSeq: 23985 ACK Max-Forwards: 70 User-Agent: Asterisk PBX 18.4.0 Content-Length: 0 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 TSX State: Terminated Inv State: CONFIRMED [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001()' [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f6c9800c2e8 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current transaction state is Terminated [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The transaction state change event is RX_MSG [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: Response is 200 OK [Aug 18 12:14:37] DEBUG[1898] chan_pjsip.c: 20001: Status: 200 [Aug 18 12:14:37] DEBUG[1898] chan_pjsip.c: 20001: No channel [Aug 18 12:14:37] DEBUG[1898] chan_pjsip.c: 20001: Status: 200 [Aug 18 12:14:37] DEBUG[1898] chan_pjsip.c: 20001: No channel [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: INVITE delay check. tsx-state:Terminated [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 TSX State: Terminated Inv State: CONFIRMED [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw)> [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: Sending delayed BYE request [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: sending delayed BYE request [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 Response 0 [Aug 18 12:14:37] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) DTLS srtp - stopped timeout timer' [Aug 18 12:14:37] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) DTLS srtp - stopped timeout timer' [Aug 18 12:14:37] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) DTLS stop [Aug 18 12:14:37] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) DTLS srtp - stopped timeout timer' [Aug 18 12:14:37] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) DTLS srtp - stopped timeout timer' [Aug 18 12:14:37] DEBUG[1898] res_rtp_asterisk.c: (0x7f6c94026c70) ICE RTP transport deallocating [Aug 18 12:14:37] DEBUG[1898] rtp_engine.c: Destroyed RTP instance '0x7f6c94026c70' [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: Method is BYE [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 [Aug 18 12:14:37] DEBUG[1898] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '192.168.10.120' [Aug 18 12:14:37] DEBUG[1898] res_pjsip/pjsip_resolver.c: Transport type for target '192.168.10.120' is 'UDP transport' [Aug 18 12:14:37] DEBUG[1898] res_pjsip/pjsip_resolver.c: Target '192.168.10.120' is an IP address, skipping resolution [Aug 18 12:14:37] VERBOSE[1898] res_pjsip_logger.c: <--- Transmitting SIP request (428 bytes) to UDP:192.168.10.120:5060 ---> BYE sip:20001@192.168.10.120:5060;ob SIP/2.0 Via: SIP/2.0/UDP 192.168.10.125:5060;rport;branch=z9hG4bKPjdf0360e4-0683-476b-abba-e5dad0b80316 From: ;tag=3655a7b6-5c61-4404-acb0-5d89b3d22674 To: ;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e CSeq: 23986 BYE Max-Forwards: 70 User-Agent: Asterisk PBX 18.4.0 Content-Length: 0 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 TSX State: Calling Inv State: CONFIRMED [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001()' [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7f6c98036468 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current transaction state is Calling [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The transaction state change event is TX_MSG [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current inv state is CONFIRMED [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 TSX State: Calling Inv State: CONFIRMED [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Topology: Pending: (null topology) Active: (null topology) [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: Terminating session on delayed BYE [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 [Aug 18 12:14:37] VERBOSE[833] res_pjsip_logger.c: <--- Received SIP response (376 bytes) from UDP:192.168.10.120:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.10.125:5060;rport=5060;received=192.168.10.125;branch=z9hG4bKPjdf0360e4-0683-476b-abba-e5dad0b80316 Call-ID: f3c7f3b1-7bbb-464c-a26a-fbac9e4ed00e From: ;tag=3655a7b6-5c61-4404-acb0-5d89b3d22674 To: ;tag=d0b18c0c-61a0-4a42-b447-781bce2fe9e1 CSeq: 23986 BYE Content-Length: 0 [Aug 18 12:14:37] DEBUG[833] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f6c9803a628 for Response msg 200/BYE/cseq=23986 (rdata0x7f6c8c003458) [Aug 18 12:14:37] DEBUG[833] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000038 associated with dialog dlg0x7f6c9803a628 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 Method: BYE Status: 200 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 Event: TSX_STATE Inv State: DISCONNCTD [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001()' [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: There is no transaction involved in this state change [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current inv state is DISCONNCTD [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: Source of transaction state change is RX_MSG [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: Received response [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: Response is 200 OK [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 TSX State: Completed Inv State: DISCONNCTD [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The state change pertains to the endpoint '20001()' [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7f6c98036468 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current transaction state is Completed [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The transaction state change event is RX_MSG [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: The current inv state is DISCONNCTD [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: Response is 200 OK [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001: BYE received final response code 200 [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Nothing delayed [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: 20001 TSX State: Completed Inv State: DISCONNCTD [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: Topology: Pending: (null topology) Active: (null topology) [Aug 18 12:14:37] DEBUG[1898] res_pjsip_session.c: [Aug 18 12:14:37] DEBUG[1898] chan_pjsip.c: 20001 [Aug 18 12:14:37] DEBUG[1898] chan_pjsip.c: No channel [Aug 18 12:14:42] DEBUG[833] res_pjsip_session.c: 20001 TSX State: Terminated Inv State: DISCONNCTD [Aug 18 12:14:42] DEBUG[833] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:14:42] DEBUG[833] res_pjsip_session.c: The state change pertains to the endpoint '20001()' [Aug 18 12:14:42] DEBUG[833] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:14:42] DEBUG[833] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7f6c98036468 [Aug 18 12:14:42] DEBUG[833] res_pjsip_session.c: The current transaction state is Terminated [Aug 18 12:14:42] DEBUG[833] res_pjsip_session.c: The transaction state change event is TIMER [Aug 18 12:14:42] DEBUG[833] res_pjsip_session.c: The current inv state is DISCONNCTD [Aug 18 12:14:42] DEBUG[1898] res_pjsip_session.c: 20001: Destroying SIP session [Aug 18 12:14:42] DEBUG[833] res_pjsip_session.c: Disconnected [Aug 18 12:14:42] DEBUG[833] res_pjsip_session.c: (null session) TSX State: Terminated Inv State: DISCONNCTD [Aug 18 12:14:42] DEBUG[833] res_pjsip_session.c: [Aug 18 12:14:44] DEBUG[845] res_pjsip_registrar.c: Woke up at 1629256484 Interval: 30 [Aug 18 12:14:44] DEBUG[845] res_pjsip_registrar.c: Expiring 0 contacts [Aug 18 12:14:57] DEBUG[1905] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 18 12:14:57] DEBUG[1903] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 18 12:14:57] DEBUG[742] threadpool.c: Destroying worker thread 133 [Aug 18 12:14:57] DEBUG[742] threadpool.c: Destroying worker thread 132 [Aug 18 12:15:09] DEBUG[833] res_pjsip_session.c: 20002 TSX State: Terminated Inv State: DISCONNCTD [Aug 18 12:15:09] DEBUG[833] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Aug 18 12:15:09] DEBUG[833] res_pjsip_session.c: The state change pertains to the endpoint '20002()' [Aug 18 12:15:09] DEBUG[833] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Aug 18 12:15:09] DEBUG[833] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f6c98091ad8 [Aug 18 12:15:09] DEBUG[833] res_pjsip_session.c: The current transaction state is Terminated [Aug 18 12:15:09] DEBUG[833] res_pjsip_session.c: The transaction state change event is TIMER [Aug 18 12:15:09] DEBUG[833] res_pjsip_session.c: The current inv state is DISCONNCTD [Aug 18 12:15:09] DEBUG[1898] res_pjsip_session.c: 20002: Destroying SIP session [Aug 18 12:15:09] DEBUG[833] res_pjsip_session.c: Disconnected [Aug 18 12:15:09] DEBUG[833] res_pjsip_session.c: (null session) TSX State: Terminated Inv State: DISCONNCTD [Aug 18 12:15:09] DEBUG[833] res_pjsip_session.c: [Aug 18 12:15:10] DEBUG[1902] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 18 12:15:10] DEBUG[1901] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 18 12:15:10] DEBUG[1900] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 18 12:15:10] DEBUG[831] threadpool.c: Destroying worker thread 131 [Aug 18 12:15:10] DEBUG[831] threadpool.c: Destroying worker thread 130 [Aug 18 12:15:10] DEBUG[831] threadpool.c: Destroying worker thread 129 [Aug 18 12:15:14] DEBUG[845] res_pjsip_registrar.c: Woke up at 1629256514 Interval: 30 [Aug 18 12:15:14] DEBUG[845] res_pjsip_registrar.c: Expiring 0 contacts