[Jun 17 10:50:04] VERBOSE[22555] config.c: == Parsing '/etc/asterisk/logger.conf': [Jun 17 10:50:04] DEBUG[22555] config.c: Parsing /etc/asterisk/logger.conf [Jun 17 10:50:04] VERBOSE[22555] config.c: == Found [Jun 17 10:50:04] VERBOSE[22555] logger.c: Asterisk Queue Logger restarted [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: <--- SIP read from UDP:172.27.2.1:5060 ---> INVITE sip:2000@redacted-asterisk-server.redacted.tld SIP/2.0 Via: SIP/2.0/UDP 172.27.2.1;branch=z9hG4bKae8b7162f1a2f902 From: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c To: Contact: Supported: replaces Call-ID: 63b4688c4e70ed30@172.27.2.1 CSeq: 24173 INVITE User-Agent: Grandstream BT110 1.0.8.33 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Type: application/sdp Content-Length: 387 v=0 o=redacted-phone 8000 8000 IN IP4 172.27.2.1 s=SIP Call c=IN IP4 172.27.2.1 t=0 0 m=audio 5004 RTP/AVP 0 8 4 18 2 97 9 101 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=20 a=rtpmap:9 G722/16000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 <-------------> [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 0 [ 43]: INVITE sip:2000@redacted-asterisk-server.redacted.tld SIP/2.0 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.27.2.1;branch=z9hG4bKae8b7162f1a2f902 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 2 [ 85]: From: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 3 [ 34]: To: [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 4 [ 39]: Contact: [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 5 [ 19]: Supported: replaces [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 6 [ 36]: Call-ID: 63b4688c4e70ed30@172.27.2.1 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 7 [ 18]: CSeq: 24173 INVITE [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 8 [ 38]: User-Agent: Grandstream BT110 1.0.8.33 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 10 [ 64]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 11 [ 29]: Content-Type: application/sdp [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 12 [ 19]: Content-Length: 387 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 13 [ 0]: [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 0 [ 3]: v=0 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 1 [ 43]: o=redacted-phone 8000 8000 IN IP4 172.27.2.1 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 2 [ 10]: s=SIP Call [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 3 [ 19]: c=IN IP4 172.27.2.1 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 4 [ 5]: t=0 0 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 5 [ 40]: m=audio 5004 RTP/AVP 0 8 4 18 2 97 9 101 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 6 [ 10]: a=sendrecv [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 8 [ 20]: a=rtpmap:8 PCMA/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 9 [ 20]: a=rtpmap:4 G723/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 10 [ 21]: a=rtpmap:18 G729/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 11 [ 23]: a=rtpmap:2 G726-32/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 12 [ 21]: a=rtpmap:97 iLBC/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 13 [ 17]: a=fmtp:97 mode=20 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 14 [ 21]: a=rtpmap:9 G722/16000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 15 [ 10]: a=ptime:20 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 16 [ 33]: a=rtpmap:101 telephone-event/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 17 [ 15]: a=fmtp:101 0-11 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: --- (13 headers 18 lines) --- [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: = Looking for Call ID: 63b4688c4e70ed30@172.27.2.1 (Checking From) --From tag 0fb773eb5ef1a77c --To-tag [Jun 17 10:50:11] DEBUG[3111] acl.c: For destination '172.27.2.1', our source address is '172.27.0.2'. [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 172.27.0.2:5060 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Allocating new SIP dialog for 63b4688c4e70ed30@172.27.2.1 - INVITE (No RTP) [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Jun 17 10:50:11] DEBUG[3111] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces" [Jun 17 10:50:11] DEBUG[3111] sip/reqresp_parser.c: Found SIP option: -replaces- [Jun 17 10:50:11] DEBUG[3111] sip/reqresp_parser.c: Matched SIP option: replaces [Jun 17 10:50:11] DEBUG[3111] netsock2.c: Splitting '172.27.2.1' into... [Jun 17 10:50:11] DEBUG[3111] netsock2.c: ...host '172.27.2.1' and port ''. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Sending to 172.27.2.1:5060 (NAT) [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Initializing initreq for method INVITE - callid 63b4688c4e70ed30@172.27.2.1 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Using INVITE request as basis request - 63b4688c4e70ed30@172.27.2.1 [Jun 17 10:50:11] DEBUG[3111] netsock2.c: Splitting 'redacted-asterisk-server.redacted.tld' into... [Jun 17 10:50:11] DEBUG[3111] netsock2.c: ...host 'redacted-asterisk-server.redacted.tld' and port ''. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found peer 'redacted-phone' for 'redacted-phone' from 172.27.2.1:5060 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: <--- Reliably Transmitting (NAT) to 172.27.2.1:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 172.27.2.1;branch=z9hG4bKae8b7162f1a2f902;received=172.27.2.1;rport=5060 From: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c To: ;tag=as1f058c6a Call-ID: 63b4688c4e70ed30@172.27.2.1 CSeq: 24173 INVITE Server: Asterisk PBX SVN-branch-10-r368645 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="0d4f0526" Content-Length: 0 <------------> [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #788 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.27.2.1:5060 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Scheduling destruction of SIP dialog '63b4688c4e70ed30@172.27.2.1' in 32000 ms (Method: INVITE) [Jun 17 10:50:11] ERROR[3111] sip/security_events.c: Bad address cast to IPv4 [Jun 17 10:50:11] ERROR[3111] sip/security_events.c: Bad address cast to IPv4 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: <--- SIP read from UDP:172.27.2.1:5060 ---> ACK sip:2000@redacted-asterisk-server.redacted.tld SIP/2.0 Via: SIP/2.0/UDP 172.27.2.1;branch=z9hG4bKae8b7162f1a2f902 From: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c To: ;tag=as1f058c6a Contact: Call-ID: 63b4688c4e70ed30@172.27.2.1 CSeq: 24173 ACK User-Agent: Grandstream BT110 1.0.8.33 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Length: 0 <-------------> [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 0 [ 40]: ACK sip:2000@redacted-asterisk-server.redacted.tld SIP/2.0 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.27.2.1;branch=z9hG4bKae8b7162f1a2f902 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 2 [ 85]: From: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 3 [ 49]: To: ;tag=as1f058c6a [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 4 [ 39]: Contact: [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 5 [ 36]: Call-ID: 63b4688c4e70ed30@172.27.2.1 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 6 [ 15]: CSeq: 24173 ACK [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 7 [ 38]: User-Agent: Grandstream BT110 1.0.8.33 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 8 [ 16]: Max-Forwards: 70 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 9 [ 64]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: --- (11 headers 0 lines) --- [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: = Looking for Call ID: 63b4688c4e70ed30@172.27.2.1 (Checking From) --From tag 0fb773eb5ef1a77c --To-tag as1f058c6a [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #788 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Stopping retransmission on '63b4688c4e70ed30@172.27.2.1' of Response 24173: Match Found [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: <--- SIP read from UDP:172.27.2.1:5060 ---> INVITE sip:2000@redacted-asterisk-server.redacted.tld SIP/2.0 Via: SIP/2.0/UDP 172.27.2.1;branch=z9hG4bKe040fd39a9ebba94 From: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c To: Contact: Supported: replaces Authorization: Digest username="redacted-phone", realm="asterisk", algorithm=MD5, uri="sip:2000@redacted-asterisk-server.redacted.tld", nonce="0d4f0526", response="redacted" Call-ID: 63b4688c4e70ed30@172.27.2.1 CSeq: 24174 INVITE User-Agent: Grandstream BT110 1.0.8.33 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Type: application/sdp Content-Length: 387 v=0 o=redacted-phone 8000 8001 IN IP4 172.27.2.1 s=SIP Call c=IN IP4 172.27.2.1 t=0 0 m=audio 5004 RTP/AVP 0 8 4 18 2 97 9 101 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=20 a=rtpmap:9 G722/16000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 <-------------> [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 0 [ 43]: INVITE sip:2000@redacted-asterisk-server.redacted.tld SIP/2.0 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.27.2.1;branch=z9hG4bKe040fd39a9ebba94 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 2 [ 85]: From: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 3 [ 34]: To: [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 4 [ 39]: Contact: [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 5 [ 19]: Supported: replaces [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 6 [178]: Authorization: Digest username="redacted-phone", realm="asterisk", algorithm=MD5, uri="sip:2000@redacted-asterisk-server.redacted.tld", nonce="0d4f0526", response="redacted" [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 7 [ 36]: Call-ID: 63b4688c4e70ed30@172.27.2.1 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 8 [ 18]: CSeq: 24174 INVITE [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 9 [ 38]: User-Agent: Grandstream BT110 1.0.8.33 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 10 [ 16]: Max-Forwards: 70 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 11 [ 64]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 13 [ 19]: Content-Length: 387 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 14 [ 0]: [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 0 [ 3]: v=0 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 1 [ 43]: o=redacted-phone 8000 8001 IN IP4 172.27.2.1 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 2 [ 10]: s=SIP Call [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 3 [ 19]: c=IN IP4 172.27.2.1 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 4 [ 5]: t=0 0 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 5 [ 40]: m=audio 5004 RTP/AVP 0 8 4 18 2 97 9 101 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 6 [ 10]: a=sendrecv [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 8 [ 20]: a=rtpmap:8 PCMA/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 9 [ 20]: a=rtpmap:4 G723/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 10 [ 21]: a=rtpmap:18 G729/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 11 [ 23]: a=rtpmap:2 G726-32/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 12 [ 21]: a=rtpmap:97 iLBC/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 13 [ 17]: a=fmtp:97 mode=20 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 14 [ 21]: a=rtpmap:9 G722/16000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 15 [ 10]: a=ptime:20 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 16 [ 33]: a=rtpmap:101 telephone-event/8000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Body 17 [ 15]: a=fmtp:101 0-11 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: --- (14 headers 18 lines) --- [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: = Looking for Call ID: 63b4688c4e70ed30@172.27.2.1 (Checking From) --From tag 0fb773eb5ef1a77c --To-tag [Jun 17 10:50:11] DEBUG[3111] netsock2.c: Splitting 'redacted-asterisk-server.redacted.tld' into... [Jun 17 10:50:11] DEBUG[3111] netsock2.c: ...host 'redacted-asterisk-server.redacted.tld' and port ''. [Jun 17 10:50:11] DEBUG[3111] netsock2.c: Splitting 'redacted-asterisk-server.redacted.tld' into... [Jun 17 10:50:11] DEBUG[3111] netsock2.c: ...host 'redacted-asterisk-server.redacted.tld' and port ''. [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Jun 17 10:50:11] DEBUG[3111] netsock2.c: Splitting '172.27.2.1' into... [Jun 17 10:50:11] DEBUG[3111] netsock2.c: ...host '172.27.2.1' and port ''. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Sending to 172.27.2.1:5060 (NAT) [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Initializing initreq for method INVITE - callid 63b4688c4e70ed30@172.27.2.1 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Using INVITE request as basis request - 63b4688c4e70ed30@172.27.2.1 [Jun 17 10:50:11] DEBUG[3111] netsock2.c: Splitting 'redacted-asterisk-server.redacted.tld' into... [Jun 17 10:50:11] DEBUG[3111] netsock2.c: ...host 'redacted-asterisk-server.redacted.tld' and port ''. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found peer 'redacted-phone' for 'redacted-phone' from 172.27.2.1:5060 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f91ac021538' [Jun 17 10:50:11] DEBUG[3111] res_rtp_asterisk.c: Allocated port 18266 for RTP instance '0x7f91ac021538' [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: RTP instance '0x7f91ac021538' is setup and ready to go [Jun 17 10:50:11] DEBUG[3111] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f91ac021538' [Jun 17 10:50:11] VERBOSE[3111] netsock2.c: == Using SIP RTP CoS mark 5 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Setting NAT on RTP to Off [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing session-level SDP o=redacted-phone 8000 8001 IN IP4 172.27.2.1... UNSUPPORTED OR FAILED. [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing session-level SDP s=SIP Call... UNSUPPORTED OR FAILED. [Jun 17 10:50:11] DEBUG[3111] netsock2.c: Splitting '172.27.2.1' into... [Jun 17 10:50:11] DEBUG[3111] netsock2.c: ...host '172.27.2.1' and port ''. [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing session-level SDP c=IN IP4 172.27.2.1... OK. [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found RTP audio format 0 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Setting payload 0 based on m type on 0x7f91b94d35b0 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found RTP audio format 8 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Setting payload 8 based on m type on 0x7f91b94d35b0 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found RTP audio format 4 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Setting payload 4 based on m type on 0x7f91b94d35b0 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found RTP audio format 18 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Setting payload 18 based on m type on 0x7f91b94d35b0 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found RTP audio format 2 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found RTP audio format 97 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Setting payload 97 based on m type on 0x7f91b94d35b0 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found RTP audio format 9 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Setting payload 9 based on m type on 0x7f91b94d35b0 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found RTP audio format 101 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Setting payload 101 based on m type on 0x7f91b94d35b0 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found audio description format PCMU for ID 0 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found audio description format PCMA for ID 8 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found audio description format G723 for ID 4 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:4 G723/8000... OK. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found audio description format G729 for ID 18 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found audio description format G726-32 for ID 2 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:2 G726-32/8000... OK. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found audio description format iLBC for ID 97 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:97 iLBC/8000... OK. [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=fmtp:97 mode=20... UNSUPPORTED OR FAILED. [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Unsetting payload 9 on 0x7f91b94d35b0 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found unknown media description format G722 for ID 9 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/16000... UNSUPPORTED OR FAILED. [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Found audio description format telephone-event for ID 101 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED. [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Incorporating payload 0 on 0x7f91b94d35b0 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Incorporating payload 2 on 0x7f91b94d35b0 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Incorporating payload 4 on 0x7f91b94d35b0 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Incorporating payload 8 on 0x7f91b94d35b0 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Incorporating payload 18 on 0x7f91b94d35b0 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Incorporating payload 97 on 0x7f91b94d35b0 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Incorporating payload 101 on 0x7f91b94d35b0 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Capabilities: us - (gsm|ulaw|alaw|h263|testlaw), peer - audio=(g723|ulaw|alaw|g726|g729|ilbc)/video=(nothing)/text=(nothing), combined - (ulaw|alaw) [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Non-codec capabilities (dtmf): us - 0x0 (nothing), peer - 0x1 (telephone-event|), combined - 0x0 (nothing) [Jun 17 10:50:11] DEBUG[3111] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f91ac021538' [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Peer audio RTP is at port 172.27.2.1:5004 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Copying payload 0 from 0x7f91b94d35b0 to 0x7f91ac021700 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Copying payload 2 from 0x7f91b94d35b0 to 0x7f91ac021700 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Copying payload 4 from 0x7f91b94d35b0 to 0x7f91ac021700 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Copying payload 8 from 0x7f91b94d35b0 to 0x7f91ac021700 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Copying payload 18 from 0x7f91b94d35b0 to 0x7f91ac021700 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Copying payload 97 from 0x7f91b94d35b0 to 0x7f91ac021700 [Jun 17 10:50:11] DEBUG[3111] rtp_engine.c: Copying payload 101 from 0x7f91b94d35b0 to 0x7f91ac021700 [Jun 17 10:50:11] DEBUG[3111] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f91ac021538' [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: We're settling with these formats: (ulaw|alaw) [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Checking SIP call limits for device redacted-phone [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Updating call counter for incoming call [Jun 17 10:50:11] DEBUG[3111] netsock2.c: Splitting 'redacted-asterisk-server.redacted.tld' into... [Jun 17 10:50:11] DEBUG[3111] netsock2.c: ...host 'redacted-asterisk-server.redacted.tld' and port ''. [Jun 17 10:50:11] DEBUG[3111] netsock2.c: Splitting 'redacted-asterisk-server.redacted.tld' into... [Jun 17 10:50:11] DEBUG[3111] netsock2.c: ...host 'redacted-asterisk-server.redacted.tld' and port ''. [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: Looking for 2000 in internal-advanced (domain redacted-asterisk-server.redacted.tld) [Jun 17 10:50:11] DEBUG[3111] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[3111] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[3111] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[3111] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[3111] pbx.c: returning an exact match-- first found-- 2000 [Jun 17 10:50:11] DEBUG[3111] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:11] DEBUG[3111] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:11] DEBUG[3111] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:11] DEBUG[3111] format_pref.c: Could not find preferred codec - Going for the best codec [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: *** Our native formats are (ulaw) [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: *** Joint capabilities are (ulaw|alaw) [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: *** Our capabilities are (gsm|ulaw|alaw|h263|testlaw) [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: This channel will not be able to handle video. [Jun 17 10:50:11] DEBUG[3111] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[3111] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[3111] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[3111] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[3111] pbx.c: returning an exact match-- first found-- 2000 [Jun 17 10:50:11] DEBUG[3111] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:11] DEBUG[3111] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:11] DEBUG[3111] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: build_route: Contact hop: [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: list_route: hop: [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: SIP/redacted-phone-00000031: New call is still down.... Trying... [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: <--- Transmitting (NAT) to 172.27.2.1:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.27.2.1;branch=z9hG4bKe040fd39a9ebba94;received=172.27.2.1;rport=5060 From: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c To: Call-ID: 63b4688c4e70ed30@172.27.2.1 CSeq: 24174 INVITE Server: Asterisk PBX SVN-branch-10-r368645 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 172.27.2.1:5060 [Jun 17 10:50:11] DEBUG[3105] devicestate.c: No provider found, checking channel drivers for SIP - redacted-phone [Jun 17 10:50:11] DEBUG[3105] chan_sip.c: Checking device state for peer redacted-phone [Jun 17 10:50:11] DEBUG[3105] devicestate.c: Changing state for SIP/redacted-phone - state 1 (Not in use) [Jun 17 10:50:11] DEBUG[3105] devicestate.c: device 'SIP/redacted-phone' state '1' [Jun 17 10:50:11] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:11] DEBUG[22556] pbx.c: returning an exact match-- first found-- 2000 [Jun 17 10:50:11] DEBUG[22556] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:11] DEBUG[22556] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:11] DEBUG[22556] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:11] DEBUG[22556] pbx.c: Launching 'Answer' [Jun 17 10:50:11] VERBOSE[22556] pbx.c: -- Executing [2000@internal-advanced:1] Answer("SIP/redacted-phone-00000031", "") in new stack [Jun 17 10:50:11] DEBUG[3105] devicestate.c: No provider found, checking channel drivers for SIP - redacted-phone [Jun 17 10:50:11] DEBUG[3105] chan_sip.c: Checking device state for peer redacted-phone [Jun 17 10:50:11] DEBUG[3105] devicestate.c: Changing state for SIP/redacted-phone - state 1 (Not in use) [Jun 17 10:50:11] DEBUG[3105] devicestate.c: device 'SIP/redacted-phone' state '1' [Jun 17 10:50:11] DEBUG[22556] chan_sip.c: SIP answering channel: SIP/redacted-phone-00000031 [Jun 17 10:50:11] DEBUG[22556] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jun 17 10:50:11] DEBUG[22556] chan_sip.c: Setting framing from config on incoming call [Jun 17 10:50:11] DEBUG[22556] chan_sip.c: ** Our capability: (ulaw|alaw) Video flag: True Text flag: True [Jun 17 10:50:11] DEBUG[22556] chan_sip.c: ** Our prefcodec: (nothing) [Jun 17 10:50:11] VERBOSE[22556] chan_sip.c: Audio is at 18266 [Jun 17 10:50:11] VERBOSE[22556] chan_sip.c: Adding codec 100003 (ulaw) to SDP [Jun 17 10:50:11] VERBOSE[22556] chan_sip.c: Adding codec 100004 (alaw) to SDP [Jun 17 10:50:11] DEBUG[22556] chan_sip.c: -- Done with adding codecs to SDP [Jun 17 10:50:11] DEBUG[22556] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw) [Jun 17 10:50:11] VERBOSE[22556] chan_sip.c: <--- Reliably Transmitting (NAT) to 172.27.2.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.27.2.1;branch=z9hG4bKe040fd39a9ebba94;received=172.27.2.1;rport=5060 From: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c To: ;tag=as41f27904 Call-ID: 63b4688c4e70ed30@172.27.2.1 CSeq: 24174 INVITE Server: Asterisk PBX SVN-branch-10-r368645 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 214 v=0 o=root 1527156416 1527156416 IN IP4 172.27.0.2 s=Asterisk PBX SVN-branch-10-r368645 c=IN IP4 172.27.0.2 t=0 0 m=audio 18266 RTP/AVP 0 8 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=ptime:20 a=sendrecv <------------> [Jun 17 10:50:11] DEBUG[22556] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #791 [Jun 17 10:50:11] DEBUG[22556] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 172.27.2.1:5060 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: <--- SIP read from UDP:172.27.2.1:5060 ---> ACK sip:2000@172.27.0.2:5060 SIP/2.0 Via: SIP/2.0/UDP 172.27.2.1;branch=z9hG4bK245ff66598f7d2a0 From: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c To: ;tag=as41f27904 Contact: Authorization: Digest username="redacted-phone", realm="asterisk", algorithm=MD5, uri="sip:2000@172.27.0.2:5060", nonce="0d4f0526", response="redacted" Call-ID: 63b4688c4e70ed30@172.27.2.1 CSeq: 24174 ACK User-Agent: Grandstream BT110 1.0.8.33 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Content-Length: 0 <-------------> [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 0 [ 36]: ACK sip:2000@172.27.0.2:5060 SIP/2.0 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.27.2.1;branch=z9hG4bK245ff66598f7d2a0 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 2 [ 85]: From: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 3 [ 49]: To: ;tag=as41f27904 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 4 [ 39]: Contact: [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 5 [174]: Authorization: Digest username="redacted-phone", realm="asterisk", algorithm=MD5, uri="sip:2000@172.27.0.2:5060", nonce="0d4f0526", response="redacted" [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 6 [ 36]: Call-ID: 63b4688c4e70ed30@172.27.2.1 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 7 [ 15]: CSeq: 24174 ACK [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 8 [ 38]: User-Agent: Grandstream BT110 1.0.8.33 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 10 [ 64]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jun 17 10:50:11] VERBOSE[3111] chan_sip.c: --- (12 headers 0 lines) --- [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: = Looking for Call ID: 63b4688c4e70ed30@172.27.2.1 (Checking From) --From tag 0fb773eb5ef1a77c --To-tag as41f27904 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #791 [Jun 17 10:50:11] DEBUG[3111] chan_sip.c: Stopping retransmission on '63b4688c4e70ed30@172.27.2.1' of Response 24174: Match Found [Jun 17 10:50:12] DEBUG[22556] channel.c: Didn't receive a media frame from SIP/redacted-phone-00000031 within 500 ms of answering. Continuing anyway [Jun 17 10:50:12] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:12] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:12] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:12] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:12] DEBUG[22556] pbx.c: returning an exact match-- first found-- 2000 [Jun 17 10:50:12] DEBUG[22556] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:12] DEBUG[22556] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:12] DEBUG[22556] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:12] DEBUG[22556] pbx.c: Launching 'WaitExten' [Jun 17 10:50:12] VERBOSE[22556] pbx.c: -- Executing [2000@internal-advanced:2] WaitExten("SIP/redacted-phone-00000031", "10") in new stack At this point, I sent "1001" as DTMF via RFC2833. Absolutely nothing was logged for it, and the next log entries occur after the timeout. [Jun 17 10:50:22] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:22] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:22] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:22] DEBUG[22556] pbx.c: Nothing strange about this match [Jun 17 10:50:22] DEBUG[22556] pbx.c: returning an exact match-- first found-- 2000 [Jun 17 10:50:22] DEBUG[22556] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:22] DEBUG[22556] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:22] DEBUG[22556] pbx.c: returning an exact match-- 2000 [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] WARNING[22556] pbx.c: Timeout but no rule 't' or 'e' in context 'internal-advanced' [Jun 17 10:50:22] DEBUG[22556] pbx.c: Spawn extension (internal-advanced,2000,2) exited non-zero on 'SIP/redacted-phone-00000031' [Jun 17 10:50:22] VERBOSE[22556] pbx.c: == Spawn extension (internal-advanced, 2000, 2) exited non-zero on 'SIP/redacted-phone-00000031' [Jun 17 10:50:22] DEBUG[22556] channel.c: Soft-Hanging up channel 'SIP/redacted-phone-00000031' [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] pbx.c: return at end of func [Jun 17 10:50:22] DEBUG[22556] channel.c: Hanging up channel 'SIP/redacted-phone-00000031' [Jun 17 10:50:22] DEBUG[22556] chan_sip.c: Hanging up zombie call. Be scared. [Jun 17 10:50:22] DEBUG[22556] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f91ac021538' [Jun 17 10:50:22] VERBOSE[22556] chan_sip.c: Scheduling destruction of SIP dialog '63b4688c4e70ed30@172.27.2.1' in 32000 ms (Method: ACK) [Jun 17 10:50:22] DEBUG[22556] chan_sip.c: Strict routing enforced for session 63b4688c4e70ed30@172.27.2.1 [Jun 17 10:50:22] VERBOSE[22556] chan_sip.c: set_destination: Parsing for address/port to send to [Jun 17 10:50:22] DEBUG[22556] netsock2.c: Splitting '172.27.2.1' into... [Jun 17 10:50:22] DEBUG[22556] netsock2.c: ...host '172.27.2.1' and port ''. [Jun 17 10:50:22] VERBOSE[22556] chan_sip.c: set_destination: set destination to 172.27.2.1:5060 [Jun 17 10:50:22] VERBOSE[22556] chan_sip.c: Reliably Transmitting (NAT) to 172.27.2.1:5060: BYE sip:redacted-phone@172.27.2.1 SIP/2.0 Via: SIP/2.0/UDP 172.27.0.2:5060;branch=z9hG4bK2ade89d3;rport Max-Forwards: 70 From: ;tag=as41f27904 To: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c Call-ID: 63b4688c4e70ed30@172.27.2.1 CSeq: 102 BYE User-Agent: Asterisk PBX SVN-branch-10-r368645 Proxy-Authorization: Digest username="redacted-phone", realm="asterisk", algorithm=MD5, uri="sip:redacted-asterisk-server.redacted.tld", nonce="", response="redacted" X-Asterisk-HangupCause: Unknown X-Asterisk-HangupCauseCode: 0 Content-Length: 0 --- [Jun 17 10:50:22] DEBUG[22556] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #793 [Jun 17 10:50:22] DEBUG[22556] chan_sip.c: Trying to put 'BYE sip:redacted' onto UDP socket destined for 172.27.2.1:5060 [Jun 17 10:50:22] DEBUG[3105] devicestate.c: No provider found, checking channel drivers for SIP - redacted-phone [Jun 17 10:50:22] DEBUG[3105] chan_sip.c: Checking device state for peer redacted-phone [Jun 17 10:50:22] DEBUG[3105] devicestate.c: Changing state for SIP/redacted-phone - state 1 (Not in use) [Jun 17 10:50:22] DEBUG[3105] devicestate.c: device 'SIP/redacted-phone' state '1' [Jun 17 10:50:22] VERBOSE[3111] chan_sip.c: <--- SIP read from UDP:172.27.2.1:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.27.0.2:5060;branch=z9hG4bK2ade89d3;rport From: ;tag=as41f27904 To: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c Call-ID: 63b4688c4e70ed30@172.27.2.1 CSeq: 102 BYE User-Agent: Grandstream BT110 1.0.8.33 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Supported: replaces Content-Length: 0 <-------------> [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Header 1 [ 61]: Via: SIP/2.0/UDP 172.27.0.2:5060;branch=z9hG4bK2ade89d3;rport [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Header 2 [ 51]: From: ;tag=as41f27904 [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Header 3 [ 83]: To: "Redacted Phone Description" ;tag=0fb773eb5ef1a77c [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Header 4 [ 36]: Call-ID: 63b4688c4e70ed30@172.27.2.1 [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Header 5 [ 13]: CSeq: 102 BYE [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Header 6 [ 38]: User-Agent: Grandstream BT110 1.0.8.33 [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Header 7 [ 39]: Contact: [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Header 8 [ 64]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Header 9 [ 19]: Supported: replaces [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Jun 17 10:50:22] VERBOSE[3111] chan_sip.c: --- (11 headers 0 lines) --- [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: = Looking for Call ID: 63b4688c4e70ed30@172.27.2.1 (Checking To) --From tag as41f27904 --To-tag 0fb773eb5ef1a77c [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #793 [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Stopping retransmission on '63b4688c4e70ed30@172.27.2.1' of Request 102: Match Found [Jun 17 10:50:22] VERBOSE[3111] chan_sip.c: SIP Response message for INCOMING dialog BYE arrived [Jun 17 10:50:22] DEBUG[3111] chan_sip.c: Destroying SIP dialog 63b4688c4e70ed30@172.27.2.1 [Jun 17 10:50:22] VERBOSE[3111] chan_sip.c: Really destroying SIP dialog '63b4688c4e70ed30@172.27.2.1' Method: ACK [Jun 17 10:50:22] DEBUG[3111] rtp_engine.c: Destroyed RTP instance '0x7f91ac021538' [Jun 17 10:50:32] VERBOSE[22555] asterisk.c: -- Remote UNIX connection disconnected [Jun 17 10:50:41] VERBOSE[3099] asterisk.c: -- Remote UNIX connection