[Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 0 [ 52]: INVITE sip:600@10.11.106.201:5061;user=phone SIP/2.0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 1 [ 68]: Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-6yeujelfbvkg;rport [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 2 [ 49]: From: ;tag=a9fw4ojvfp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 3 [ 43]: To: [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 4 [ 34]: Call-ID: 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 5 [ 14]: CSeq: 1 INVITE [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 7 [ 73]: Contact: ;reg-id=1 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 8 [ 28]: X-Serialnumber: 000413261D97 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 9 [ 41]: P-Key-Flags: resolution="31x13", keys="4" [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 10 [ 25]: User-Agent: snom370/8.5.4 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 11 [ 23]: Accept: application/sdp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 12 [ 96]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 13 [ 42]: Allow-Events: talk, hold, refer, call-info [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 14 [ 47]: Supported: timer, 100rel, replaces, from-change [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 15 [ 35]: Session-Expires: 3600;refresher=uas [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 16 [ 10]: Min-SE: 90 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 17 [ 29]: Content-Type: application/sdp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 18 [ 19]: Content-Length: 485 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 19 [ 0]: <--- SIP read from TLS:10.11.106.18:2151 ---> INVITE sip:600@10.11.106.201:5061;user=phone SIP/2.0 Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-6yeujelfbvkg;rport From: ;tag=a9fw4ojvfp To: Call-ID: 3c2676833af5-p9pxqmssqqum CSeq: 1 INVITE Max-Forwards: 70 Contact: ;reg-id=1 X-Serialnumber: 000413261D97 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom370/8.5.4 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 485 v=0 o=root 1919400803 1919400803 IN IP4 10.11.106.18 s=call c=IN IP4 10.11.106.18 t=0 0 m=audio 51338 RTP/SAVP 0 8 106 107 18 9 101 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:CEWqy3W+liYKH6d4iNQwI4y4hqXtzxJ7Qj5YgKiy a=direction:both a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:106 g726-32/8000 a=rtpmap:107 aal2-g726-32/8000 a=rtpmap:18 g729/8000 a=fmtp:18 annexb=no a=rtpmap:9 g722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv <-------------> [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 0 [ 52]: INVITE sip:600@10.11.106.201:5061;user=phone SIP/2.0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 1 [ 68]: Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-6yeujelfbvkg;rport [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 2 [ 49]: From: ;tag=a9fw4ojvfp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 3 [ 43]: To: [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 4 [ 34]: Call-ID: 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 5 [ 14]: CSeq: 1 INVITE [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 7 [ 73]: Contact: ;reg-id=1 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 8 [ 28]: X-Serialnumber: 000413261D97 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 9 [ 41]: P-Key-Flags: resolution="31x13", keys="4" [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 10 [ 25]: User-Agent: snom370/8.5.4 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 11 [ 23]: Accept: application/sdp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 12 [ 96]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 13 [ 42]: Allow-Events: talk, hold, refer, call-info [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 14 [ 47]: Supported: timer, 100rel, replaces, from-change [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 15 [ 35]: Session-Expires: 3600;refresher=uas [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 16 [ 10]: Min-SE: 90 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 17 [ 29]: Content-Type: application/sdp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 18 [ 19]: Content-Length: 485 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 19 [ 0]: [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 0 [ 3]: v=0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 1 [ 48]: o=root 1919400803 1919400803 IN IP4 10.11.106.18 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 2 [ 6]: s=call [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 3 [ 21]: c=IN IP4 10.11.106.18 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 4 [ 5]: t=0 0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 5 [ 43]: m=audio 51338 RTP/SAVP 0 8 106 107 18 9 101 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 6 [ 82]: a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:CEWqy3W+liYKH6d4iNQwI4y4hqXtzxJ7Qj5YgKiy [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 7 [ 16]: a=direction:both [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 8 [ 20]: a=rtpmap:0 pcmu/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 9 [ 20]: a=rtpmap:8 pcma/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 10 [ 25]: a=rtpmap:106 g726-32/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 11 [ 30]: a=rtpmap:107 aal2-g726-32/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 12 [ 21]: a=rtpmap:18 g729/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 13 [ 19]: a=fmtp:18 annexb=no [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 14 [ 20]: a=rtpmap:9 g722/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 15 [ 33]: a=rtpmap:101 telephone-event/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 16 [ 15]: a=fmtp:101 0-15 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 17 [ 10]: a=ptime:20 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7808 parse_request: Body 18 [ 10]: a=sendrecv --- (19 headers 19 lines) --- [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7374 find_call: = Looking for Call ID: 3c2676833af5-p9pxqmssqqum (Checking From) --From tag a9fw4ojvfp --To-tag [Sep 28 06:18:16] DEBUG[13966]: acl.c:715 ast_ouraddrfor: For destination '10.11.106.18', our source address is '10.11.106.201'. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:3240 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_TLS with address 10.11.106.201:5061 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7174 sip_alloc: Allocating new SIP dialog for 3c2676833af5-p9pxqmssqqum - INVITE (No RTP) [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:23492 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE [Sep 28 06:18:16] DEBUG[13966]: sip/reqresp_parser.c:1584 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, from-change" [Sep 28 06:18:16] DEBUG[13966]: sip/reqresp_parser.c:1600 parse_sip_options: Found SIP option: -timer- [Sep 28 06:18:16] DEBUG[13966]: sip/reqresp_parser.c:1608 parse_sip_options: Matched SIP option: timer [Sep 28 06:18:16] DEBUG[13966]: sip/reqresp_parser.c:1600 parse_sip_options: Found SIP option: -100rel- [Sep 28 06:18:16] DEBUG[13966]: sip/reqresp_parser.c:1608 parse_sip_options: Matched SIP option: 100rel [Sep 28 06:18:16] DEBUG[13966]: sip/reqresp_parser.c:1600 parse_sip_options: Found SIP option: -replaces- [Sep 28 06:18:16] DEBUG[13966]: sip/reqresp_parser.c:1608 parse_sip_options: Matched SIP option: replaces [Sep 28 06:18:16] DEBUG[13966]: sip/reqresp_parser.c:1600 parse_sip_options: Found SIP option: -from-change- [Sep 28 06:18:16] DEBUG[13966]: sip/reqresp_parser.c:1608 parse_sip_options: Matched SIP option: from-change [Sep 28 06:18:16] DEBUG[13966]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.11.106.18:2151' gives... [Sep 28 06:18:16] DEBUG[13966]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.11.106.18' and port '2151'. Sending to 10.11.106.18:2151 (no NAT) [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:21077 handle_request_invite: Initializing initreq for method INVITE - callid 3c2676833af5-p9pxqmssqqum Using INVITE request as basis request - 3c2676833af5-p9pxqmssqqum Found peer '432' for '432' from 10.11.106.18:2151 <--- Reliably Transmitting (no NAT) to 10.11.106.18:2151 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-6yeujelfbvkg;received=10.11.106.18;rport=2151 From: ;tag=a9fw4ojvfp To: ;tag=as644aca01 Call-ID: 3c2676833af5-p9pxqmssqqum CSeq: 1 INVITE Server: Asterisk PBX SVN-branch-1.8-r288640 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="659c644a" Content-Length: 0 <------------> [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:3086 __sip_xmit: Trying to put 'SIP/2.0 401' onto TLS socket destined for 10.11.106.18:2151 Scheduling destruction of SIP dialog '3c2676833af5-p9pxqmssqqum' in 32000 ms (Method: INVITE) [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 0 [ 49]: ACK sip:600@10.11.106.201:5061;user=phone SIP/2.0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 1 [ 68]: Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-6yeujelfbvkg;rport [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 2 [ 49]: From: ;tag=a9fw4ojvfp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 3 [ 58]: To: ;tag=as644aca01 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 4 [ 34]: Call-ID: 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 5 [ 11]: CSeq: 1 ACK [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 7 [ 73]: Contact: ;reg-id=1 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 8 [ 17]: Content-Length: 0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 9 [ 0]: <--- SIP read from TLS:10.11.106.18:2151 ---> ACK sip:600@10.11.106.201:5061;user=phone SIP/2.0 Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-6yeujelfbvkg;rport From: ;tag=a9fw4ojvfp To: ;tag=as644aca01 Call-ID: 3c2676833af5-p9pxqmssqqum CSeq: 1 ACK Max-Forwards: 70 Contact: ;reg-id=1 Content-Length: 0 <-------------> [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 0 [ 49]: ACK sip:600@10.11.106.201:5061;user=phone SIP/2.0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 1 [ 68]: Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-6yeujelfbvkg;rport [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 2 [ 49]: From: ;tag=a9fw4ojvfp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 3 [ 58]: To: ;tag=as644aca01 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 4 [ 34]: Call-ID: 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 5 [ 11]: CSeq: 1 ACK [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 7 [ 73]: Contact: ;reg-id=1 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 8 [ 17]: Content-Length: 0 --- (9 headers 0 lines) --- [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7374 find_call: = Looking for Call ID: 3c2676833af5-p9pxqmssqqum (Checking From) --From tag a9fw4ojvfp --To-tag as644aca01 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:23492 handle_incoming: **** Received ACK (6) - Command in SIP ACK [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:3761 __sip_ack: Stopping retransmission on '3c2676833af5-p9pxqmssqqum' of Response 1: Match Not Found [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 0 [ 52]: INVITE sip:600@10.11.106.201:5061;user=phone SIP/2.0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 1 [ 68]: Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-mw5k4loqnxpw;rport [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 2 [ 49]: From: ;tag=a9fw4ojvfp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 3 [ 43]: To: [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 4 [ 34]: Call-ID: 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 5 [ 14]: CSeq: 2 INVITE [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 7 [ 73]: Contact: ;reg-id=1 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 8 [ 28]: X-Serialnumber: 000413261D97 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 9 [ 41]: P-Key-Flags: resolution="31x13", keys="4" [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 10 [ 25]: User-Agent: snom370/8.5.4 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 11 [ 23]: Accept: application/sdp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 12 [ 96]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 13 [ 42]: Allow-Events: talk, hold, refer, call-info [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 14 [ 47]: Supported: timer, 100rel, replaces, from-change [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 15 [ 35]: Session-Expires: 3600;refresher=uas [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 16 [ 10]: Min-SE: 90 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 17 [172]: Authorization: Digest username="432",realm="asterisk",nonce="659c644a",uri="sip:600@10.11.106.201:5061;user=phone",response="3dc24c61354b7a5a0292d1d1e070ab1b",algorithm=MD5 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 18 [ 29]: Content-Type: application/sdp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 19 [ 19]: Content-Length: 485 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 20 [ 0]: <--- SIP read from TLS:10.11.106.18:2151 ---> INVITE sip:600@10.11.106.201:5061;user=phone SIP/2.0 Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-mw5k4loqnxpw;rport From: ;tag=a9fw4ojvfp To: Call-ID: 3c2676833af5-p9pxqmssqqum CSeq: 2 INVITE Max-Forwards: 70 Contact: ;reg-id=1 X-Serialnumber: 000413261D97 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom370/8.5.4 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Session-Expires: 3600;refresher=uas Min-SE: 90 Authorization: Digest username="432",realm="asterisk",nonce="659c644a",uri="sip:600@10.11.106.201:5061;user=phone",response="3dc24c61354b7a5a0292d1d1e070ab1b",algorithm=MD5 Content-Type: application/sdp Content-Length: 485 v=0 o=root 1919400803 1919400803 IN IP4 10.11.106.18 s=call c=IN IP4 10.11.106.18 t=0 0 m=audio 51338 RTP/SAVP 0 8 106 107 18 9 101 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:CEWqy3W+liYKH6d4iNQwI4y4hqXtzxJ7Qj5YgKiy a=direction:both a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:106 g726-32/8000 a=rtpmap:107 aal2-g726-32/8000 a=rtpmap:18 g729/8000 a=fmtp:18 annexb=no a=rtpmap:9 g722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv <-------------> [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 0 [ 52]: INVITE sip:600@10.11.106.201:5061;user=phone SIP/2.0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 1 [ 68]: Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-mw5k4loqnxpw;rport [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 2 [ 49]: From: ;tag=a9fw4ojvfp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 3 [ 43]: To: [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 4 [ 34]: Call-ID: 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 5 [ 14]: CSeq: 2 INVITE [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 7 [ 73]: Contact: ;reg-id=1 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 8 [ 28]: X-Serialnumber: 000413261D97 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 9 [ 41]: P-Key-Flags: resolution="31x13", keys="4" [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 10 [ 25]: User-Agent: snom370/8.5.4 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 11 [ 23]: Accept: application/sdp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 12 [ 96]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 13 [ 42]: Allow-Events: talk, hold, refer, call-info [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 14 [ 47]: Supported: timer, 100rel, replaces, from-change [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 15 [ 35]: Session-Expires: 3600;refresher=uas [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 16 [ 10]: Min-SE: 90 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 17 [172]: Authorization: Digest username="432",realm="asterisk",nonce="659c644a",uri="sip:600@10.11.106.201:5061;user=phone",response="3dc24c61354b7a5a0292d1d1e070ab1b",algorithm=MD5 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 18 [ 29]: Content-Type: application/sdp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 19 [ 19]: Content-Length: 485 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 20 [ 0]: [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 0 [ 3]: v=0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 1 [ 48]: o=root 1919400803 1919400803 IN IP4 10.11.106.18 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 2 [ 6]: s=call [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 3 [ 21]: c=IN IP4 10.11.106.18 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 4 [ 5]: t=0 0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 5 [ 43]: m=audio 51338 RTP/SAVP 0 8 106 107 18 9 101 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 6 [ 82]: a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:CEWqy3W+liYKH6d4iNQwI4y4hqXtzxJ7Qj5YgKiy [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 7 [ 16]: a=direction:both [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 8 [ 20]: a=rtpmap:0 pcmu/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 9 [ 20]: a=rtpmap:8 pcma/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 10 [ 25]: a=rtpmap:106 g726-32/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 11 [ 30]: a=rtpmap:107 aal2-g726-32/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 12 [ 21]: a=rtpmap:18 g729/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 13 [ 19]: a=fmtp:18 annexb=no [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 14 [ 20]: a=rtpmap:9 g722/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 15 [ 33]: a=rtpmap:101 telephone-event/8000 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 16 [ 15]: a=fmtp:101 0-15 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Body 17 [ 10]: a=ptime:20 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7808 parse_request: Body 18 [ 10]: a=sendrecv --- (20 headers 19 lines) --- [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7374 find_call: = Looking for Call ID: 3c2676833af5-p9pxqmssqqum (Checking From) --From tag a9fw4ojvfp --To-tag [Sep 28 06:18:16] DEBUG[13966]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.11.106.201:5061' gives... [Sep 28 06:18:16] DEBUG[13966]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.11.106.201' and port '5061'. [Sep 28 06:18:16] DEBUG[13966]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.11.106.201:5061' gives... [Sep 28 06:18:16] DEBUG[13966]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.11.106.201' and port '5061'. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:23492 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE [Sep 28 06:18:16] DEBUG[13966]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.11.106.18:2151' gives... [Sep 28 06:18:16] DEBUG[13966]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.11.106.18' and port '2151'. Sending to 10.11.106.18:2151 (no NAT) [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:21077 handle_request_invite: Initializing initreq for method INVITE - callid 3c2676833af5-p9pxqmssqqum Using INVITE request as basis request - 3c2676833af5-p9pxqmssqqum Found peer '432' for '432' from 10.11.106.18:2151 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:344 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0xbd66240' [Sep 28 06:18:16] DEBUG[13966]: res_rtp_asterisk.c:470 ast_rtp_new: Allocated port 19602 for RTP instance '0xbd66240' [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:353 ast_rtp_instance_new: RTP instance '0xbd66240' is setup and ready to go [Sep 28 06:18:16] DEBUG[13966]: res_rtp_asterisk.c:2352 ast_rtp_prop_set: Setup RTCP on RTP instance '0xbd66240' == Using SIP RTP CoS mark 5 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:4651 do_setnat: Setting NAT on RTP to Off [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8126 process_sdp: Processing session-level SDP v=0... UNSUPPORTED. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8126 process_sdp: Processing session-level SDP o=root 1919400803 1919400803 IN IP4 10.11.106.18... UNSUPPORTED. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8126 process_sdp: Processing session-level SDP s=call... UNSUPPORTED. [Sep 28 06:18:16] DEBUG[13966]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.11.106.18' gives... [Sep 28 06:18:16] DEBUG[13966]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.11.106.18' and port '(null)'. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8126 process_sdp: Processing session-level SDP c=IN IP4 10.11.106.18... OK. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8126 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED. Found RTP audio format 0 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:523 ast_rtp_codecs_payloads_set_m_type: Setting payload 0 based on m type on 0xb2c282a0 Found RTP audio format 8 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:523 ast_rtp_codecs_payloads_set_m_type: Setting payload 8 based on m type on 0xb2c282a0 Found RTP audio format 106 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:523 ast_rtp_codecs_payloads_set_m_type: Setting payload 106 based on m type on 0xb2c282a0 Found RTP audio format 107 Found RTP audio format 18 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:523 ast_rtp_codecs_payloads_set_m_type: Setting payload 18 based on m type on 0xb2c282a0 Found RTP audio format 9 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:523 ast_rtp_codecs_payloads_set_m_type: Setting payload 9 based on m type on 0xb2c282a0 Found RTP audio format 101 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:523 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0xb2c282a0 [Sep 28 06:18:16] DEBUG[13966]: sip/sdp_crypto.c:101 sdp_crypto_setup: local_key64 dWKj0ULnTOxdkgobYYYKrhWcCdfi+w0s+8q4Yyp3 len 40 [Sep 28 06:18:16] DEBUG[13966]: sip/sdp_crypto.c:176 sdp_crypto_activate: SRTP policy activated [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:CEWqy3W+liYKH6d4iNQwI4y4hqXtzxJ7Qj5YgKiy... OK. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=direction:both... UNSUPPORTED. Found audio description format pcmu for ID 0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 pcmu/8000... OK. Found audio description format pcma for ID 8 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=rtpmap:8 pcma/8000... OK. Found audio description format g726-32 for ID 106 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=rtpmap:106 g726-32/8000... OK. Found audio description format aal2-g726-32 for ID 107 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=rtpmap:107 aal2-g726-32/8000... OK. Found audio description format g729 for ID 18 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=rtpmap:18 g729/8000... OK. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED. Found audio description format g722 for ID 9 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 g722/8000... OK. Found audio description format telephone-event for ID 101 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=ptime:20... OK. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8313 process_sdp: Processing media-level (audio) SDP a=sendrecv... OK. [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:626 ast_rtp_codecs_payload_formats: Incorporating payload 0 on 0xb2c282a0 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:626 ast_rtp_codecs_payload_formats: Incorporating payload 8 on 0xb2c282a0 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:626 ast_rtp_codecs_payload_formats: Incorporating payload 9 on 0xb2c282a0 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:626 ast_rtp_codecs_payload_formats: Incorporating payload 18 on 0xb2c282a0 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:626 ast_rtp_codecs_payload_formats: Incorporating payload 101 on 0xb2c282a0 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:626 ast_rtp_codecs_payload_formats: Incorporating payload 106 on 0xb2c282a0 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:626 ast_rtp_codecs_payload_formats: Incorporating payload 107 on 0xb2c282a0 Capabilities: us - 0x80000008000e (gsm|ulaw|alaw|h263|testlaw), peer - audio=0x191c (ulaw|alaw|g726|g729|g726aal2|g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Sep 28 06:18:16] DEBUG[13966]: res_rtp_asterisk.c:2373 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0xbd66240' Peer audio RTP is at port 10.11.106.18:51338 [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:504 ast_rtp_codecs_payloads_copy: Copying payload 0 from 0xb2c282a0 to 0xbd663ec [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:504 ast_rtp_codecs_payloads_copy: Copying payload 8 from 0xb2c282a0 to 0xbd663ec [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:504 ast_rtp_codecs_payloads_copy: Copying payload 9 from 0xb2c282a0 to 0xbd663ec [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:504 ast_rtp_codecs_payloads_copy: Copying payload 18 from 0xb2c282a0 to 0xbd663ec [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:504 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0xb2c282a0 to 0xbd663ec [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:504 ast_rtp_codecs_payloads_copy: Copying payload 106 from 0xb2c282a0 to 0xbd663ec [Sep 28 06:18:16] DEBUG[13966]: rtp_engine.c:504 ast_rtp_codecs_payloads_copy: Copying payload 107 from 0xb2c282a0 to 0xbd663ec [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:8545 process_sdp: We're settling with these formats: 0xc (ulaw|alaw) [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:21216 handle_request_invite: Checking SIP call limits for device 432 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:5418 update_call_counter: Updating call counter for incoming call [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:5523 update_call_counter: Call from peer '432' is 1 out of 20 [Sep 28 06:18:16] DEBUG[13828]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for SIP - 432 [Sep 28 06:18:16] DEBUG[13828]: chan_sip.c:24806 sip_devicestate: Checking device state for peer 432 [Sep 28 06:18:16] DEBUG[13828]: devicestate.c:458 do_state_change: Changing state for SIP/432 - state 2 (In use) [Sep 28 06:18:16] DEBUG[13828]: devicestate.c:438 devstate_event: device 'SIP/432' state '2' [Sep 28 06:18:16] DEBUG[13863]: app_queue.c:1324 handle_statechange: Device 'SIP/432' changed to state '2' (In use) but we don't care because they're not a member of any queue. Looking for 600 in telefone (domain 10.11.106.201:5061) [Sep 28 06:18:16] DEBUG[13966]: frame.c:1242 ast_codec_choose: Could not find preferred codec - Going for the best codec [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:6521 sip_new: *** Our native formats are 0x4 (ulaw) [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:6522 sip_new: *** Joint capabilities are 0xc (ulaw|alaw) [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:6523 sip_new: *** Our capabilities are 0x80000008000e (gsm|ulaw|alaw|h263|testlaw) [Sep 28 06:18:16] DEBUG[13966]: frame.c:1242 ast_codec_choose: Could not find preferred codec - Going for the best codec [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:6524 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:6554 sip_new: This channel will not be able to handle video. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:13198 build_route: build_route: Contact hop: ;reg-id=1 list_route: hop: [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:21319 handle_request_invite: Incoming INVITE with 'timer' option supported and "Session-Expires" header. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:24508 parse_session_expires: Session-Expires: 3600 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:24524 parse_session_expires: Refresher: UAS [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:24478 parse_minse: Received Min-SE: 90 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:24378 start_session_timer: Session timer started: 168 - 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:21507 handle_request_invite: SIP/432-0000000f: New call is still down.... Trying... <--- Transmitting (no NAT) to 10.11.106.18:2151 ---> SIP/2.0 100 Trying Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-mw5k4loqnxpw;received=10.11.106.18;rport=2151 From: ;tag=a9fw4ojvfp To: Call-ID: 3c2676833af5-p9pxqmssqqum CSeq: 2 INVITE Server: Asterisk PBX SVN-branch-1.8-r288640 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Session-Expires: 1800;refresher=uas Contact: Content-Length: 0 <------------> [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:3086 __sip_xmit: Trying to put 'SIP/2.0 100' onto TLS socket destined for 10.11.106.18:2151 [Sep 28 06:18:16] DEBUG[13828]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for SIP - 432 [Sep 28 06:18:16] DEBUG[13828]: chan_sip.c:24806 sip_devicestate: Checking device state for peer 432 [Sep 28 06:18:16] DEBUG[13828]: devicestate.c:458 do_state_change: Changing state for SIP/432 - state 2 (In use) [Sep 28 06:18:16] DEBUG[13828]: devicestate.c:438 devstate_event: device 'SIP/432' state '2' [Sep 28 06:18:16] DEBUG[13863]: app_queue.c:1324 handle_statechange: Device 'SIP/432' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 28 06:18:16] DEBUG[14055]: pbx.c:4055 pbx_extension_helper: Launching 'Set' -- Executing [600@telefone:1] Set("SIP/432-0000000f", "_SIP_SRTP_SDES=1") in new stack [Sep 28 06:18:16] DEBUG[14055]: pbx.c:4055 pbx_extension_helper: Launching 'Set' -- Executing [600@telefone:2] Set("SIP/432-0000000f", "_SIPSRTP=enable") in new stack [Sep 28 06:18:16] DEBUG[14055]: pbx.c:4055 pbx_extension_helper: Launching 'Set' -- Executing [600@telefone:3] Set("SIP/432-0000000f", "_SIPSRTP_CRYPTO=enable") in new stack [Sep 28 06:18:16] DEBUG[14055]: pbx.c:4055 pbx_extension_helper: Launching 'Playback' -- Executing [600@telefone:4] Playback("SIP/432-0000000f", "demo-echotest") in new stack [Sep 28 06:18:16] DEBUG[14055]: chan_sip.c:5992 sip_answer: SIP answering channel: SIP/432-0000000f [Sep 28 06:18:16] DEBUG[14055]: res_rtp_asterisk.c:712 ast_rtp_update_source: Setting the marker bit due to a source update [Sep 28 06:18:16] DEBUG[14055]: chan_sip.c:10872 transmit_response_with_sdp: Setting framing from config on incoming call [Sep 28 06:18:16] DEBUG[14055]: chan_sip.c:10516 add_sdp: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True [Sep 28 06:18:16] DEBUG[14055]: chan_sip.c:10517 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 5061 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Sep 28 06:18:16] DEBUG[14055]: chan_sip.c:10628 add_sdp: -- Done with adding codecs to SDP [Sep 28 06:18:16] DEBUG[14055]: chan_sip.c:10767 add_sdp: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) <--- Reliably Transmitting (no NAT) to 10.11.106.18:2151 ---> SIP/2.0 200 OK Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-mw5k4loqnxpw;received=10.11.106.18;rport=2151 From: ;tag=a9fw4ojvfp To: ;tag=as14c61d3b Call-ID: 3c2676833af5-p9pxqmssqqum CSeq: 2 INVITE Server: Asterisk PBX SVN-branch-1.8-r288640 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Session-Expires: 1800;refresher=uas Contact: Content-Type: application/sdp Content-Length: 389 v=0 o=root 1671003243 1671003243 IN IP4 10.11.106.201 s=Asterisk PBX SVN-branch-1.8-r288640 c=IN IP4 10.11.106.201 t=0 0 m=audio 19602 RTP/SAVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:dWKj0ULnTOxdkgobYYYKrhWcCdfi+w0s+8q4Yyp3 <------------> [Sep 28 06:18:16] DEBUG[14055]: chan_sip.c:3086 __sip_xmit: Trying to put 'SIP/2.0 200' onto TLS socket destined for 10.11.106.18:2151 [Sep 28 06:18:16] DEBUG[13828]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for SIP - 432 [Sep 28 06:18:16] DEBUG[13828]: chan_sip.c:24806 sip_devicestate: Checking device state for peer 432 [Sep 28 06:18:16] DEBUG[13828]: devicestate.c:458 do_state_change: Changing state for SIP/432 - state 2 (In use) [Sep 28 06:18:16] DEBUG[13828]: devicestate.c:438 devstate_event: device 'SIP/432' state '2' [Sep 28 06:18:16] DEBUG[13863]: app_queue.c:1324 handle_statechange: Device 'SIP/432' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 0 [ 52]: ACK sip:600@10.11.106.201:5061;transport=TLS SIP/2.0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 1 [ 68]: Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-a20599vr7pam;rport [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 2 [ 49]: From: ;tag=a9fw4ojvfp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 3 [ 58]: To: ;tag=as14c61d3b [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 4 [ 34]: Call-ID: 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 5 [ 11]: CSeq: 2 ACK [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 7 [ 73]: Contact: ;reg-id=1 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 8 [ 17]: Content-Length: 0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 9 [ 0]: <--- SIP read from TLS:10.11.106.18:2151 ---> ACK sip:600@10.11.106.201:5061;transport=TLS SIP/2.0 Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-a20599vr7pam;rport From: ;tag=a9fw4ojvfp To: ;tag=as14c61d3b Call-ID: 3c2676833af5-p9pxqmssqqum CSeq: 2 ACK Max-Forwards: 70 Contact: ;reg-id=1 Content-Length: 0 <-------------> [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 0 [ 52]: ACK sip:600@10.11.106.201:5061;transport=TLS SIP/2.0 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 1 [ 68]: Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-a20599vr7pam;rport [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 2 [ 49]: From: ;tag=a9fw4ojvfp [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 3 [ 58]: To: ;tag=as14c61d3b [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 4 [ 34]: Call-ID: 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 5 [ 11]: CSeq: 2 ACK [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 7 [ 73]: Contact: ;reg-id=1 [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 8 [ 17]: Content-Length: 0 --- (9 headers 0 lines) --- [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:7374 find_call: = Looking for Call ID: 3c2676833af5-p9pxqmssqqum (Checking From) --From tag a9fw4ojvfp --To-tag as14c61d3b [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:23492 handle_incoming: **** Received ACK (6) - Command in SIP ACK [Sep 28 06:18:16] DEBUG[13966]: chan_sip.c:3761 __sip_ack: Stopping retransmission on '3c2676833af5-p9pxqmssqqum' of Response 2: Match Not Found [Sep 28 06:18:16] DEBUG[14055]: channel.c:2825 __ast_answer: Didn't receive a media frame from SIP/432-0000000f within 500 ms of answering. Continuing anyway [Sep 28 06:18:16] DEBUG[14055]: channel.c:4940 set_format: Set channel SIP/432-0000000f to write format gsm [Sep 28 06:18:16] DEBUG[14055]: res_rtp_asterisk.c:1226 ast_rtp_write: Ooh, format changed from unknown to ulaw [Sep 28 06:18:16] DEBUG[14055]: res_rtp_asterisk.c:1257 ast_rtp_write: Created smoother: format: ulaw ms: 20 len: 160 [Sep 28 06:18:16] DEBUG[14055]: res_rtp_asterisk.c:1127 ast_rtp_raw_write: Starting RTCP transmission on RTP instance '0xbd66240' Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034821, ts 000160, len 000170) [Sep 28 06:18:16] DEBUG[14055]: channel.c:3370 ast_settimeout: Scheduling timer at (50 requested / 50 actual) timer ticks per second -- Playing 'demo-echotest.gsm' (language 'en') [Sep 28 06:18:17] WARNING[14055]: res_srtp.c:346 ast_srtp_unprotect: SRTP unprotect: authentication failure [Sep 28 06:18:17] WARNING[14055]: res_srtp.c:346 ast_srtp_unprotect: SRTP unprotect: authentication failure Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034822, ts 000320, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034823, ts 000480, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034824, ts 000640, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024240, ts 13298568, len 000160) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024241, ts 13298728, len 000160) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024242, ts 13299128, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034825, ts 000800, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024243, ts 13299288, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034826, ts 000960, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024244, ts 13299448, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034827, ts 001120, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034828, ts 001280, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034829, ts 001440, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024245, ts 13299608, len 000160) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024246, ts 13299768, len 000160) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024247, ts 13299928, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034830, ts 001600, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024248, ts 13300088, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034831, ts 001760, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024249, ts 13300248, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034832, ts 001920, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024250, ts 13300408, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034833, ts 002080, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024251, ts 13300568, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034834, ts 002240, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024252, ts 13300728, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034835, ts 002400, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024253, ts 13300888, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034836, ts 002560, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024254, ts 13301048, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034837, ts 002720, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024255, ts 13301208, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034838, ts 002880, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024256, ts 13301368, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034839, ts 003040, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024257, ts 13301528, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034840, ts 003200, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024258, ts 13301688, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034841, ts 003360, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024259, ts 13301848, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034842, ts 003520, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024260, ts 13302008, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034843, ts 003680, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024261, ts 13302168, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034844, ts 003840, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024262, ts 13302328, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034845, ts 004000, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024263, ts 13302488, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034846, ts 004160, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024264, ts 13302648, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034847, ts 004320, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024265, ts 13302808, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034848, ts 004480, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024266, ts 13302968, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034849, ts 004640, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024267, ts 13303128, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034850, ts 004800, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024268, ts 13303288, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034851, ts 004960, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024269, ts 13303448, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034852, ts 005120, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024270, ts 13303608, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034853, ts 005280, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024271, ts 13303768, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034854, ts 005440, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024272, ts 13303928, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034855, ts 005600, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024273, ts 13304088, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034856, ts 005760, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024274, ts 13304248, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034857, ts 005920, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024275, ts 13304408, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034858, ts 006080, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024276, ts 13304568, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034859, ts 006240, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024277, ts 13304728, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034860, ts 006400, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024278, ts 13304888, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034861, ts 006560, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024279, ts 13305048, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034862, ts 006720, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024280, ts 13305208, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034863, ts 006880, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024281, ts 13305368, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034864, ts 007040, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024282, ts 13305528, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034865, ts 007200, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024283, ts 13305688, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034866, ts 007360, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024284, ts 13305848, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034867, ts 007520, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024285, ts 13306008, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034868, ts 007680, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024286, ts 13306168, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034869, ts 007840, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024287, ts 13306328, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034870, ts 008000, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024288, ts 13306488, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034871, ts 008160, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024289, ts 13306648, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034872, ts 008320, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024290, ts 13306808, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034873, ts 008480, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024291, ts 13306968, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034874, ts 008640, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024292, ts 13307128, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034875, ts 008800, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024293, ts 13307288, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034876, ts 008960, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024294, ts 13307448, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034877, ts 009120, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024295, ts 13307608, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034878, ts 009280, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024296, ts 13307768, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034879, ts 009440, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024297, ts 13307928, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034880, ts 009600, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024298, ts 13308088, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034881, ts 009760, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024299, ts 13308248, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034882, ts 009920, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024300, ts 13308408, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034883, ts 010080, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024301, ts 13308568, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034884, ts 010240, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024302, ts 13308728, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034885, ts 010400, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024303, ts 13308888, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034886, ts 010560, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024304, ts 13309048, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034887, ts 010720, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024305, ts 13309208, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034888, ts 010880, len 000170) Got RTP packet from 10.11.106.18:51338 (type 00, seq 024306, ts 13309368, len 000160) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034889, ts 011040, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034890, ts 011200, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034891, ts 011360, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034892, ts 011520, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034893, ts 011680, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034894, ts 011840, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034895, ts 012000, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034896, ts 012160, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034897, ts 012320, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034898, ts 012480, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034899, ts 012640, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034900, ts 012800, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034901, ts 012960, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034902, ts 013120, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034903, ts 013280, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034904, ts 013440, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034905, ts 013600, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034906, ts 013760, len 000170) Sent RTP packet to 10.11.106.18:51338 (type 00, seq 034907, ts 013920, len 000170) [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 0 [ 52]: BYE sip:600@10.11.106.201:5061;transport=TLS SIP/2.0 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 1 [ 68]: Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-vpxqtxpftuzh;rport [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 2 [ 49]: From: ;tag=a9fw4ojvfp [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 3 [ 58]: To: ;tag=as14c61d3b [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 4 [ 34]: Call-ID: 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 5 [ 11]: CSeq: 3 BYE [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 7 [ 73]: Contact: ;reg-id=1 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 8 [ 25]: User-Agent: snom370/8.5.4 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 9 [ 75]: RTP-RxStat: Total_Rx_Pkts=65,Rx_Pkts=0,Rx_Pkts_Lost=1,Remote_Rx_Pkts_Lost=0 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 10 [ 56]: RTP-TxStat: Total_Tx_Pkts=65,Tx_Pkts=73,Remote_Tx_Pkts=0 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 11 [ 17]: Content-Length: 0 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 12 [ 0]: <--- SIP read from TLS:10.11.106.18:2151 ---> BYE sip:600@10.11.106.201:5061;transport=TLS SIP/2.0 Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-vpxqtxpftuzh;rport From: ;tag=a9fw4ojvfp To: ;tag=as14c61d3b Call-ID: 3c2676833af5-p9pxqmssqqum CSeq: 3 BYE Max-Forwards: 70 Contact: ;reg-id=1 User-Agent: snom370/8.5.4 RTP-RxStat: Total_Rx_Pkts=65,Rx_Pkts=0,Rx_Pkts_Lost=1,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=65,Tx_Pkts=73,Remote_Tx_Pkts=0 Content-Length: 0 <-------------> [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 0 [ 52]: BYE sip:600@10.11.106.201:5061;transport=TLS SIP/2.0 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 1 [ 68]: Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-vpxqtxpftuzh;rport [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 2 [ 49]: From: ;tag=a9fw4ojvfp [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 3 [ 58]: To: ;tag=as14c61d3b [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 4 [ 34]: Call-ID: 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 5 [ 11]: CSeq: 3 BYE [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 7 [ 73]: Contact: ;reg-id=1 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 8 [ 25]: User-Agent: snom370/8.5.4 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 9 [ 75]: RTP-RxStat: Total_Rx_Pkts=65,Rx_Pkts=0,Rx_Pkts_Lost=1,Remote_Rx_Pkts_Lost=0 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 10 [ 56]: RTP-TxStat: Total_Tx_Pkts=65,Tx_Pkts=73,Remote_Tx_Pkts=0 [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7771 parse_request: Header 11 [ 17]: Content-Length: 0 --- (12 headers 0 lines) --- [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:7374 find_call: = Looking for Call ID: 3c2676833af5-p9pxqmssqqum (Checking From) --From tag a9fw4ojvfp --To-tag as14c61d3b [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:23492 handle_incoming: **** Received BYE (8) - Command in SIP BYE [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:22267 handle_request_bye: Initializing initreq for method BYE - callid 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:18] DEBUG[13966]: netsock2.c:125 ast_sockaddr_split_hostport: Splitting '10.11.106.18:2151' gives... [Sep 28 06:18:18] DEBUG[13966]: netsock2.c:155 ast_sockaddr_split_hostport: ...host '10.11.106.18' and port '2151'. Sending to 10.11.106.18:2151 (no NAT) [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:2833 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 3c2676833af5-p9pxqmssqqum [Sep 28 06:18:18] DEBUG[13966]: res_rtp_asterisk.c:2373 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0xbd66240' [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:24359 stop_session_timer: Session timer stopped: -1 - 3c2676833af5-p9pxqmssqqum Scheduling destruction of SIP dialog '3c2676833af5-p9pxqmssqqum' in 32000 ms (Method: BYE) [Sep 28 06:18:18] DEBUG[13966]: chan_sip.c:22370 handle_request_bye: Received bye, issuing owner hangup <--- Transmitting (no NAT) to 10.11.106.18:2151 ---> SIP/2.0 200 OK Via: SIP/2.0/TLS 10.11.106.18:2151;branch=z9hG4bK-vpxqtxpftuzh;received=10.11.106.18;rport=2151 From: ;tag=a9fw4ojvfp To: ;tag=as14c61d3b Call-ID: 3c2676833af5-p9pxqmssqqum CSeq: 3 BYE Server: Asterisk PBX SVN-branch-1.8-r288640 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0