[Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: ˙<--- SIP read from UDP:59.167.211.8:3964 ---> ˙INVITE sip:0403000000@bebe.MYDOMAIN.com.au SIP/2.0 ˙Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-au7ye62g8sw2;rport ˙From: "Nick Adams [ReachTEL]" ;tag=4t4f4q418t ˙To: ˙Call-ID: 3c30e3708588-qga585hc6now ˙CSeq: 1 INVITE ˙Max-Forwards: 70 ˙Contact: ;reg-id=1 ˙X-Serialnumber: 00041324ECFE ˙P-Key-Flags: keys="3" ˙User-Agent: snom320/8.4.32 ˙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: 218 ˙ ˙v=0 ˙o=root 212884761 212884761 IN IP4 59.167.211.8 ˙s=call ˙c=IN IP4 59.167.211.8 ˙t=0 0 ˙m=audio 10032 RTP/AVP 8 101 ˙a=rtpmap:8 PCMA/8000 ˙a=rtpmap:101 telephone-event/8000 ˙a=fmtp:101 0-16 ˙a=ptime:20 ˙a=sendrecv ˙<-------------> [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 0 [ 50]: INVITE sip:0403000000@bebe.MYDOMAIN.com.au SIP/2.0 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-au7ye62g8sw2;rport [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 2 [ 75]: From: "Nick Adams [Company]" ;tag=4t4f4q418t [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 3 [ 41]: To: [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 4 [ 34]: Call-ID: 3c30e3708588-qga585hc6now [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 5 [ 14]: CSeq: 1 INVITE [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 7 [ 59]: Contact: ;reg-id=1 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 8 [ 28]: X-Serialnumber: 00041324ECFE [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 9 [ 21]: P-Key-Flags: keys="3" [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 10 [ 26]: User-Agent: snom320/8.4.32 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 11 [ 23]: Accept: application/sdp [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 12 [ 96]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 13 [ 42]: Allow-Events: talk, hold, refer, call-info [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 14 [ 47]: Supported: timer, 100rel, replaces, from-change [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 15 [ 35]: Session-Expires: 3600;refresher=uas [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 16 [ 10]: Min-SE: 90 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 17 [ 29]: Content-Type: application/sdp [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 18 [ 19]: Content-Length: 218 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 19 [ 0]: [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 0 [ 3]: v=0 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 1 [ 46]: o=root 212884761 212884761 IN IP4 59.167.211.8 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 2 [ 6]: s=call [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 3 [ 21]: c=IN IP4 59.167.211.8 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 4 [ 5]: t=0 0 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 5 [ 27]: m=audio 10032 RTP/AVP 8 101 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-16 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 10 [ 10]: a=sendrecv [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: --- (19 headers 11 lines) --- [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: = Looking for Call ID: 3c30e3708588-qga585hc6now (Checking From) --From tag 4t4f4q418t --To-tag [Mar 18 07:38:23] DEBUG[11932] acl.c: For destination '59.167.211.8', our source address is '103.17.217.6'. [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 103.17.217.6:5060 [Mar 18 07:38:23] DEBUG[11932] netsock2.c: Splitting '59.167.211.8:3964' into... [Mar 18 07:38:23] DEBUG[11932] netsock2.c: ...host '59.167.211.8' and port '3964'. [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: Sending to 59.167.211.8:3964 (no NAT) [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Allocating new SIP dialog for 3c30e3708588-qga585hc6now - INVITE (No RTP) [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Mar 18 07:38:23] DEBUG[11932][C-0000000f] sip/reqresp_parser.c: Begin: parsing SIP "Supported: timer, 100rel, replaces, from-change" [Mar 18 07:38:23] DEBUG[11932][C-0000000f] sip/reqresp_parser.c: Found SIP option: -timer- [Mar 18 07:38:23] DEBUG[11932][C-0000000f] sip/reqresp_parser.c: Matched SIP option: timer [Mar 18 07:38:23] DEBUG[11932][C-0000000f] sip/reqresp_parser.c: Found SIP option: -100rel- [Mar 18 07:38:23] DEBUG[11932][C-0000000f] sip/reqresp_parser.c: Matched SIP option: 100rel [Mar 18 07:38:23] DEBUG[11932][C-0000000f] sip/reqresp_parser.c: Found SIP option: -replaces- [Mar 18 07:38:23] DEBUG[11932][C-0000000f] sip/reqresp_parser.c: Matched SIP option: replaces [Mar 18 07:38:23] DEBUG[11932][C-0000000f] sip/reqresp_parser.c: Found SIP option: -from-change- [Mar 18 07:38:23] DEBUG[11932][C-0000000f] sip/reqresp_parser.c: Matched SIP option: from-change [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: Splitting '59.167.211.8:3964' into... [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: ...host '59.167.211.8' and port '3964'. [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Sending to 59.167.211.8:3964 (no NAT) [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Initializing initreq for method INVITE - callid 3c30e3708588-qga585hc6now [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Using INVITE request as basis request - 3c30e3708588-qga585hc6now [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: Splitting 'bebe.MYDOMAIN.com.au' into... [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: ...host 'bebe.MYDOMAIN.com.au' and port ''. [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Found peer '506' for '506' from 59.167.211.8:3964 [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: ˙<--- Reliably Transmitting (no NAT) to 59.167.211.8:3964 ---> ˙SIP/2.0 401 Unauthorized ˙Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-au7ye62g8sw2;received=59.167.211.8;rport=3964 ˙From: "Nick Adams [Company]" ;tag=4t4f4q418t ˙To: ;tag=as2ffffb77 ˙Call-ID: 3c30e3708588-qga585hc6now ˙CSeq: 1 INVITE ˙Server: Asterisk PBX 11.8.1 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="4c74d982" ˙Content-Length: 0 ˙ ˙ ˙<------------> [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #40343 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 59.167.211.8:3964 [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Scheduling destruction of SIP dialog '3c30e3708588-qga585hc6now' in 6400 ms (Method: INVITE) [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: ˙<--- SIP read from UDP:59.167.211.8:3964 ---> ˙ACK sip:0403000000@bebe.MYDOMAIN.com.au SIP/2.0 ˙Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-au7ye62g8sw2;rport ˙From: "Nick Adams [Company]" ;tag=4t4f4q418t ˙To: ;tag=as2ffffb77 ˙Call-ID: 3c30e3708588-qga585hc6now ˙CSeq: 1 ACK ˙Max-Forwards: 70 ˙Contact: ;reg-id=1 ˙Content-Length: 0 ˙ ˙<-------------> [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 0 [ 47]: ACK sip:0403000000@bebe.MYDOMAIN.com.au SIP/2.0 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-au7ye62g8sw2;rport [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 2 [ 75]: From: "Nick Adams [Company]" ;tag=4t4f4q418t [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 3 [ 56]: To: ;tag=as2ffffb77 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 4 [ 34]: Call-ID: 3c30e3708588-qga585hc6now [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 5 [ 11]: CSeq: 1 ACK [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 7 [ 59]: Contact: ;reg-id=1 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: --- (9 headers 0 lines) --- [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: = Looking for Call ID: 3c30e3708588-qga585hc6now (Checking From) --From tag 4t4f4q418t --To-tag as2ffffb77 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #40343 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Stopping retransmission on '3c30e3708588-qga585hc6now' of Response 1: Match Found [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: ˙<--- SIP read from UDP:59.167.211.8:3964 ---> ˙INVITE sip:0403000000@bebe.MYDOMAIN.com.au SIP/2.0 ˙Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-0i7ofjt37h97;rport ˙From: "Nick Adams [Company]" ;tag=4t4f4q418t ˙To: ˙Call-ID: 3c30e3708588-qga585hc6now ˙CSeq: 2 INVITE ˙Max-Forwards: 70 ˙Contact: ;reg-id=1 ˙X-Serialnumber: 00041324ECFE ˙P-Key-Flags: keys="3" ˙User-Agent: snom320/8.4.32 ˙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="506",realm="asterisk",nonce="4c74d982",uri="sip:0403000000@bebe.MYDOMAIN.com.au",response="639d8dd7055cf85b5c09234cc6f755c1",algorithm=MD5 ˙Content-Type: application/sdp ˙Content-Length: 218 ˙ ˙v=0 ˙o=root 212884761 212884761 IN IP4 59.167.211.8 ˙s=call ˙c=IN IP4 59.167.211.8 ˙t=0 0 ˙m=audio 10032 RTP/AVP 8 101 ˙a=rtpmap:8 PCMA/8000 ˙a=rtpmap:101 telephone-event/8000 ˙a=fmtp:101 0-16 ˙a=ptime:20 ˙a=sendrecv ˙<-------------> [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 0 [ 50]: INVITE sip:0403000000@bebe.MYDOMAIN.com.au SIP/2.0 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-0i7ofjt37h97;rport [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 2 [ 75]: From: "Nick Adams [Company]" ;tag=4t4f4q418t [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 3 [ 41]: To: [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 4 [ 34]: Call-ID: 3c30e3708588-qga585hc6now [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 5 [ 14]: CSeq: 2 INVITE [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 7 [ 59]: Contact: ;reg-id=1 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 8 [ 28]: X-Serialnumber: 00041324ECFE [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 9 [ 21]: P-Key-Flags: keys="3" [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 10 [ 26]: User-Agent: snom320/8.4.32 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 11 [ 23]: Accept: application/sdp [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 12 [ 96]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO, UPDATE [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 13 [ 42]: Allow-Events: talk, hold, refer, call-info [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 14 [ 47]: Supported: timer, 100rel, replaces, from-change [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 15 [ 35]: Session-Expires: 3600;refresher=uas [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 16 [ 10]: Min-SE: 90 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 17 [170]: Authorization: Digest username="506",realm="asterisk",nonce="4c74d982",uri="sip:0403000000@bebe.MYDOMAIN.com.au",response="639d8dd7055cf85b5c09234cc6f755c1",algorithm=MD5 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 18 [ 29]: Content-Type: application/sdp [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 19 [ 19]: Content-Length: 218 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 20 [ 0]: [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 0 [ 3]: v=0 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 1 [ 46]: o=root 212884761 212884761 IN IP4 59.167.211.8 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 2 [ 6]: s=call [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 3 [ 21]: c=IN IP4 59.167.211.8 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 4 [ 5]: t=0 0 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 5 [ 27]: m=audio 10032 RTP/AVP 8 101 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-16 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Body 10 [ 10]: a=sendrecv [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: --- (20 headers 11 lines) --- [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: = Looking for Call ID: 3c30e3708588-qga585hc6now (Checking From) --From tag 4t4f4q418t --To-tag [Mar 18 07:38:23] DEBUG[11932] netsock2.c: Splitting 'bebe.MYDOMAIN.com.au' into... [Mar 18 07:38:23] DEBUG[11932] netsock2.c: ...host 'bebe.MYDOMAIN.com.au' and port ''. [Mar 18 07:38:23] DEBUG[11932] netsock2.c: Splitting 'bebe.MYDOMAIN.com.au' into... [Mar 18 07:38:23] DEBUG[11932] netsock2.c: ...host 'bebe.MYDOMAIN.com.au' and port ''. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: Splitting '59.167.211.8:3964' into... [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: ...host '59.167.211.8' and port '3964'. [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Sending to 59.167.211.8:3964 (no NAT) [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Initializing initreq for method INVITE - callid 3c30e3708588-qga585hc6now [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Using INVITE request as basis request - 3c30e3708588-qga585hc6now [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: Splitting 'bebe.MYDOMAIN.com.au' into... [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: ...host 'bebe.MYDOMAIN.com.au' and port ''. [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Found peer '506' for '506' from 59.167.211.8:3964 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f9bc00386b8' [Mar 18 07:38:23] DEBUG[11932][C-0000000f] res_rtp_asterisk.c: Allocated port 17382 for RTP instance '0x7f9bc00386b8' [Mar 18 07:38:23] DEBUG[11932][C-0000000f] rtp_engine.c: RTP instance '0x7f9bc00386b8' is setup and ready to go [Mar 18 07:38:23] DEBUG[11932][C-0000000f] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f9bc00386b8' [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Setting NAT on RTP to Off [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Processing session-level SDP o=root 212884761 212884761 IN IP4 59.167.211.8... OK. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Processing session-level SDP s=call... UNSUPPORTED OR FAILED. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: Splitting '59.167.211.8' into... [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: ...host '59.167.211.8' and port ''. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Processing session-level SDP c=IN IP4 59.167.211.8... OK. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Found RTP audio format 8 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] rtp_engine.c: Setting payload 8 based on m type on 0x7f9bd2d7bfb0 [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Found RTP audio format 101 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] rtp_engine.c: Setting payload 101 based on m type on 0x7f9bd2d7bfb0 [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Found audio description format PCMA for ID 8 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Found audio description format telephone-event for ID 101 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED OR FAILED. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Capabilities: us - (alaw), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw) [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Mar 18 07:38:23] DEBUG[11932][C-0000000f] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f9bc00386b8' [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Peer audio RTP is at port 59.167.211.8:10032 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] rtp_engine.c: Copying payload 8 from 0x7f9bd2d7bfb0 to 0x7f9bc0038880 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] rtp_engine.c: Copying payload 101 from 0x7f9bd2d7bfb0 to 0x7f9bc0038880 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f9bc00386b8' [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: We're settling with these formats: (alaw) [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Checking SIP call limits for device 506 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Updating call counter for incoming call [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Call from peer '506' is 1 out of 2147483647 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: Splitting 'bebe.MYDOMAIN.com.au' into... [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: ...host 'bebe.MYDOMAIN.com.au' and port ''. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: Splitting 'bebe.MYDOMAIN.com.au' into... [Mar 18 07:38:23] DEBUG[11932][C-0000000f] netsock2.c: ...host 'bebe.MYDOMAIN.com.au' and port ''. [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Looking for 0403000000 in Company-SIP-Handsets (domain bebe.MYDOMAIN.com.au) [Mar 18 07:38:23] DEBUG[11921] devicestate.c: No provider found, checking channel drivers for SIP - 506 [Mar 18 07:38:23] DEBUG[11921] chan_sip.c: Checking device state for peer 506 [Mar 18 07:38:23] DEBUG[11921] devicestate.c: Changing state for SIP/506 - state 2 (In use) [Mar 18 07:38:23] DEBUG[11921] devicestate.c: device 'SIP/506' state '2' [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Incoming INVITE with 'timer' option supported [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: INVITE also has "Session-Expires" header. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Session-Expires: 3600 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Refresher: UAS [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: INVITE also has "Min-SE" header. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Received Min-SE: 90 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: *** Our native formats are (alaw) [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: *** Joint capabilities are (alaw) [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: *** Our capabilities are (alaw) [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: This channel will not be able to handle video. [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: build_route: Contact hop: ;reg-id=1 [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: list_route: hop: [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Session timer started: 40345 - 3c30e3708588-qga585hc6now 900000ms [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: SIP/506-0000001b: New call is still down.... Trying... [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: ˙<--- Transmitting (no NAT) to 59.167.211.8:3964 ---> ˙SIP/2.0 100 Trying ˙Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-0i7ofjt37h97;received=59.167.211.8;rport=3964 ˙From: "Nick Adams [Company]" ;tag=4t4f4q418t ˙To: ˙Call-ID: 3c30e3708588-qga585hc6now ˙CSeq: 2 INVITE ˙Server: Asterisk PBX 11.8.1 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Session-Expires: 1800;refresher=uas ˙Contact: ˙Content-Length: 0 ˙ ˙ ˙<------------> [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 59.167.211.8:3964 [Mar 18 07:38:23] DEBUG[11923] app_queue.c: Extension '506@Company-SIP-Handsets' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 18 07:38:23] DEBUG[11921] devicestate.c: No provider found, checking channel drivers for SIP - 506 [Mar 18 07:38:23] DEBUG[11943] app_queue.c: Device 'SIP/506' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 18 07:38:23] DEBUG[11921] chan_sip.c: Checking device state for peer 506 [Mar 18 07:38:23] DEBUG[11921] devicestate.c: Changing state for SIP/506 - state 2 (In use) [Mar 18 07:38:23] DEBUG[11921] devicestate.c: device 'SIP/506' state '2' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Function CALLERID(num) result is '506' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Launching 'Set' [Mar 18 07:38:23] DEBUG[11943] app_queue.c: Device 'SIP/506' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Result of 'EXTEN' is '0403000000' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Launching 'Goto' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Result of 'EXTEN' is '0403000000' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Launching 'Goto' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Result of 'EXTEN' is '61403000000' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Launching 'Dial' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Asked to create a SIP channel with formats: (alaw) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Allocating new SIP dialog for 4e5a46ad7647748026fefe5002d83003@103.17.217.6:5060 - INVITE (No RTP) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f9b87e2c518' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] res_rtp_asterisk.c: Allocated port 10688 for RTP instance '0x7f9b87e2c518' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] rtp_engine.c: RTP instance '0x7f9b87e2c518' is setup and ready to go [Mar 18 07:38:23] DEBUG[4677][C-0000000f] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f9b87e2c518' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Setting NAT on RTP to Off [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Mar 18 07:38:23] DEBUG[4677][C-0000000f] acl.c: For destination '172.25.59.1', our source address is '172.25.59.250'. [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Setting NAT on RTP to Off [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: SIP call-id changed from '4e5a46ad7647748026fefe5002d83003@103.17.217.6:5060' to '186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** Our native formats are (alaw) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** Joint capabilities are (alaw) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** Our capabilities are (alaw) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** Our preferred formats from the incoming channel are (alaw) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: This channel will not be able to handle video. [Mar 18 07:38:23] DEBUG[4677][C-0000000f] channel_internal_api.c: Channel Call ID changing from [C-0000000f] to [C-0000000f] [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Outgoing Call for 61403000000 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Updating call counter for outgoing call [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Call to peer 'NetSIPBrisbane1' is 1 out of 2147483647 [Mar 18 07:38:23] DEBUG[11921] devicestate.c: No provider found, checking channel drivers for SIP - NetSIPBrisbane1 [Mar 18 07:38:23] DEBUG[11921] chan_sip.c: Checking device state for peer NetSIPBrisbane1 [Mar 18 07:38:23] DEBUG[11921] devicestate.c: Changing state for SIP/NetSIPBrisbane1 - state 6 (Ringing) [Mar 18 07:38:23] DEBUG[11921] devicestate.c: device 'SIP/NetSIPBrisbane1' state '6' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: ** Our capability: (alaw) Video flag: False Text flag: False [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: ** Our prefcodec: (alaw) [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: Audio is at 10688 [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: Adding codec 100004 (alaw) to SDP [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: -- Done with adding codecs to SDP [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [Mar 18 07:38:23] DEBUG[11943] app_queue.c: Device 'SIP/NetSIPBrisbane1' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Initializing initreq for method INVITE - callid 186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 0 [ 42]: INVITE sip:61403000000@172.25.59.1 SIP/2.0 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK5d1a5d8e [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 3 [ 75]: From: "Nick Adams [Company]" ;tag=as6bb9a20c [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 4 [ 33]: To: [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 5 [ 44]: Contact: [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 6 [ 60]: Call-ID: 186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 8 [ 31]: User-Agent: Asterisk PBX 11.8.1 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 9 [ 35]: Date: Mon, 17 Mar 2014 21:38:23 GMT [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: Reliably Transmitting (no NAT) to 172.25.59.1:5060: ˙INVITE sip:61403000000@172.25.59.1 SIP/2.0 ˙Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK5d1a5d8e ˙Max-Forwards: 70 ˙From: "Nick Adams [Company]" ;tag=as6bb9a20c ˙To: ˙Contact: ˙Call-ID: 186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060 ˙CSeq: 102 INVITE ˙User-Agent: Asterisk PBX 11.8.1 ˙Date: Mon, 17 Mar 2014 21:38:23 GMT ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Content-Type: application/sdp ˙Content-Length: 262 ˙ ˙v=0 ˙o=root 514270074 514270074 IN IP4 172.25.59.250 ˙s=Asterisk PBX 11.8.1 ˙c=IN IP4 172.25.59.250 ˙t=0 0 ˙m=audio 10688 RTP/AVP 8 101 ˙a=rtpmap:8 PCMA/8000 ˙a=rtpmap:101 telephone-event/8000 ˙a=fmtp:101 0-16 ˙a=silenceSupp:off - - - - ˙a=ptime:20 ˙a=sendrecv ˙ ˙--- [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #40347 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 172.25.59.1:5060 [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: ˙<--- SIP read from UDP:172.25.59.1:5060 ---> ˙SIP/2.0 300 Redirect ˙Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK5d1a5d8e ˙From: "Nick Adams [Company]" ;tag=as6bb9a20c ˙To: ;tag=ee46ceb4ace2d5a7afc962898f49aa95.d6c1 ˙Call-ID: 186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060 ˙CSeq: 102 INVITE ˙Contact: sip:61403000000@172.25.59.11:5060 ˙Server: kamailio (3.3.2 (x86_64/linux)) ˙Content-Length: 0 ˙ ˙<-------------> [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 0 [ 20]: SIP/2.0 300 Redirect [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK5d1a5d8e [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 2 [ 75]: From: "Nick Adams [Company]" ;tag=as6bb9a20c [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 3 [ 75]: To: ;tag=ee46ceb4ace2d5a7afc962898f49aa95.d6c1 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 4 [ 60]: Call-ID: 186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 6 [ 42]: Contact: sip:61403000000@172.25.59.11:5060 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 7 [ 39]: Server: kamailio (3.3.2 (x86_64/linux)) [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: --- (9 headers 0 lines) --- [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: = Looking for Call ID: 186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060 (Checking To) --From tag as6bb9a20c --To-tag ee46ceb4ace2d5a7afc962898f49aa95.d6c1 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Acked pending invite 102 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #40347 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Stopping retransmission on '186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060' of Request 102: Match Found [Mar 18 07:38:23] DEBUG[11932][C-0000000f] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f9b87e2c518' [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Found promiscuous redirection to 'SIP/61403000000::::UDP@172.25.59.11:5060' [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Got redirecting from number 61403000000 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Got redirecting to number 61403000000 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Asked to create a SIP channel with formats: (alaw) [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Transmitting (no NAT) to 172.25.59.1:5060: ˙ACK sip:61403000000@172.25.59.1 SIP/2.0 ˙Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK5d1a5d8e ˙Max-Forwards: 70 ˙From: "Nick Adams [Company]" ;tag=as6bb9a20c ˙To: ;tag=ee46ceb4ace2d5a7afc962898f49aa95.d6c1 ˙Contact: ˙Call-ID: 186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060 ˙CSeq: 102 ACK ˙User-Agent: Asterisk PBX 11.8.1 ˙Content-Length: 0 ˙ ˙ ˙--- [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Trying to put 'ACK sip:614' onto UDP socket destined for 172.25.59.1:5060 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Setting SIP_ALREADYGONE on dialog 186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Allocating new SIP dialog for 3bba80a07ce7d96c7ff3ea291152ddd8@103.17.217.6:5060 - INVITE (No RTP) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f9b87e21c78' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] res_rtp_asterisk.c: Allocated port 10952 for RTP instance '0x7f9b87e21c78' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] rtp_engine.c: RTP instance '0x7f9b87e21c78' is setup and ready to go [Mar 18 07:38:23] DEBUG[4677][C-0000000f] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f9b87e21c78' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Setting NAT on RTP to Off [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Mar 18 07:38:23] DEBUG[4677][C-0000000f] netsock2.c: Splitting '172.25.59.11:5060' into... [Mar 18 07:38:23] DEBUG[4677][C-0000000f] netsock2.c: ...host '172.25.59.11' and port '5060'. [Mar 18 07:38:23] DEBUG[4677][C-0000000f] acl.c: For destination '172.25.59.11', our source address is '172.25.59.250'. [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Setting NAT on RTP to Off [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: SIP call-id changed from '3bba80a07ce7d96c7ff3ea291152ddd8@103.17.217.6:5060' to '0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** Our native formats are (alaw) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** Joint capabilities are (alaw) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** Our capabilities are (alaw) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** Our preferred formats from the incoming channel are (alaw) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: This channel will not be able to handle video. [Mar 18 07:38:23] DEBUG[4677][C-0000000f] channel_internal_api.c: Channel Call ID changing from [C-0000000f] to [C-0000000f] [Mar 18 07:38:23] NOTICE[4677][C-0000000f] app_dial.c: Not accepting call completion offers from call-forward recipient SIP/172.25.59.11:5060-0000001d [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: ˙<--- Transmitting (no NAT) to 59.167.211.8:3964 ---> ˙SIP/2.0 181 Call is being forwarded ˙Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-0i7ofjt37h97;received=59.167.211.8;rport=3964 ˙From: "Nick Adams [Company]" ;tag=4t4f4q418t ˙To: ;tag=as4aabe939 ˙Call-ID: 3c30e3708588-qga585hc6now ˙CSeq: 2 INVITE ˙Server: Asterisk PBX 11.8.1 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Session-Expires: 1800;refresher=uas ˙Contact: ˙Diversion: ;reason=unconditional ˙Content-Length: 0 ˙ ˙ ˙<------------> [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Trying to put 'SIP/2.0 181' onto UDP socket destined for 59.167.211.8:3964 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Outgoing Call for 61403000000 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Updating call counter for outgoing call [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: ** Our capability: (alaw) Video flag: False Text flag: False [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: ** Our prefcodec: (alaw) [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: Audio is at 10952 [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: Adding codec 100004 (alaw) to SDP [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: -- Done with adding codecs to SDP [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Initializing initreq for method INVITE - callid 0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 0 [ 48]: INVITE sip:61403000000@172.25.59.11:5060 SIP/2.0 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK64438bc3 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 3 [ 75]: From: "Nick Adams [Company]" ;tag=as4932d8de [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 4 [ 39]: To: [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 5 [ 44]: Contact: [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 6 [ 60]: Call-ID: 0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 8 [ 31]: User-Agent: Asterisk PBX 11.8.1 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 9 [ 35]: Date: Mon, 17 Mar 2014 21:38:23 GMT [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 12 [ 63]: Diversion: ;reason=unconditional [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: Reliably Transmitting (no NAT) to 172.25.59.11:5060: ˙INVITE sip:61403000000@172.25.59.11:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK64438bc3 ˙Max-Forwards: 70 ˙From: "Nick Adams [Company]" ;tag=as4932d8de ˙To: ˙Contact: ˙Call-ID: 0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060 ˙CSeq: 102 INVITE ˙User-Agent: Asterisk PBX 11.8.1 ˙Date: Mon, 17 Mar 2014 21:38:23 GMT ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Diversion: ;reason=unconditional ˙Content-Type: application/sdp ˙Content-Length: 264 ˙ ˙v=0 ˙o=root 1573724880 1573724880 IN IP4 172.25.59.250 ˙s=Asterisk PBX 11.8.1 ˙c=IN IP4 172.25.59.250 ˙t=0 0 ˙m=audio 10952 RTP/AVP 8 101 ˙a=rtpmap:8 PCMA/8000 ˙a=rtpmap:101 telephone-event/8000 ˙a=fmtp:101 0-16 ˙a=silenceSupp:off - - - - ˙a=ptime:20 ˙a=sendrecv ˙ ˙--- [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #40349 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 172.25.59.11:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] channel.c: Hanging up channel 'SIP/NetSIPBrisbane1-0000001c' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Hangup call SIP/NetSIPBrisbane1-0000001c, SIP callid 186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: update_call_counter(61403000000) - decrement call limit counter on hangup [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Updating call counter for outgoing call [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Call to peer 'NetSIPBrisbane1' removed from call limit 2147483647 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f9b87e2c518' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] cdr.c: Dropping CDR ! [Mar 18 07:38:23] DEBUG[11921] devicestate.c: No provider found, checking channel drivers for SIP - NetSIPBrisbane1 [Mar 18 07:38:23] DEBUG[11921] chan_sip.c: Checking device state for peer NetSIPBrisbane1 [Mar 18 07:38:23] DEBUG[11921] devicestate.c: Changing state for SIP/NetSIPBrisbane1 - state 1 (Not in use) [Mar 18 07:38:23] DEBUG[11921] devicestate.c: device 'SIP/NetSIPBrisbane1' state '1' [Mar 18 07:38:23] DEBUG[11921] devicestate.c: No provider found, checking channel drivers for SIP - NetSIPBrisbane1 [Mar 18 07:38:23] DEBUG[11921] chan_sip.c: Checking device state for peer NetSIPBrisbane1 [Mar 18 07:38:23] DEBUG[11921] devicestate.c: Changing state for SIP/NetSIPBrisbane1 - state 1 (Not in use) [Mar 18 07:38:23] DEBUG[11921] devicestate.c: device 'SIP/NetSIPBrisbane1' state '1' [Mar 18 07:38:23] DEBUG[11943] app_queue.c: Device 'SIP/NetSIPBrisbane1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 18 07:38:23] DEBUG[11943] app_queue.c: Device 'SIP/NetSIPBrisbane1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: ˙<--- SIP read from UDP:172.25.59.11:5060 ---> ˙SIP/2.0 100 Trying ˙Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK64438bc3;rport=5060 ˙From: "Nick Adams [Company]" ;tag=as4932d8de ˙To: ˙Call-ID: 0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060 ˙CSeq: 102 INVITE ˙User-Agent: FreeSWITCH-mod_sofia/1.2.10+git~20130624T144607Z~998ae35dbf ˙Content-Length: 0 ˙ ˙<-------------> [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 1 [ 69]: Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK64438bc3;rport=5060 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 2 [ 75]: From: "Nick Adams [Company]" ;tag=as4932d8de [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 3 [ 39]: To: [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 4 [ 60]: Call-ID: 0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 6 [ 71]: User-Agent: FreeSWITCH-mod_sofia/1.2.10+git~20130624T144607Z~998ae35dbf [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: --- (8 headers 0 lines) --- [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: = Looking for Call ID: 0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060 (Checking To) --From tag as4932d8de --To-tag [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: *** SIP TIMER: Cancelling retransmission #40349 - INVITE (got response) [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060' Request 102: Found [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: SIP response 100 to standard invite [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Destroying SIP dialog 186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060 [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: Really destroying SIP dialog '186efab3679f43322d0f6ca817d2c000@172.25.59.250:5060' Method: INVITE [Mar 18 07:38:23] DEBUG[11932] rtp_engine.c: Destroyed RTP instance '0x7f9b87e2c518' [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: ˙<--- SIP read from UDP:172.25.59.11:5060 ---> ˙SIP/2.0 404 Not Found ˙Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK64438bc3;rport=5060 ˙Max-Forwards: 68 ˙From: "Nick Adams [Company]" ;tag=as4932d8de ˙To: ;tag=BKBg920c77tcB ˙Call-ID: 0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060 ˙CSeq: 102 INVITE ˙User-Agent: FreeSWITCH-mod_sofia/1.2.10+git~20130624T144607Z~998ae35dbf ˙Accept: application/sdp ˙Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY ˙Supported: timer, precondition, path, replaces ˙Allow-Events: talk, hold, conference, refer ˙Reason: Q.850;cause=3;text="NO_ROUTE_DESTINATION" ˙Content-Length: 0 ˙ ˙<-------------> [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 0 [ 21]: SIP/2.0 404 Not Found [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 1 [ 69]: Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK64438bc3;rport=5060 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 2 [ 16]: Max-Forwards: 68 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 3 [ 75]: From: "Nick Adams [Company]" ;tag=as4932d8de [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 4 [ 57]: To: ;tag=BKBg920c77tcB [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 5 [ 60]: Call-ID: 0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 7 [ 71]: User-Agent: FreeSWITCH-mod_sofia/1.2.10+git~20130624T144607Z~998ae35dbf [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 8 [ 23]: Accept: application/sdp [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 10 [ 46]: Supported: timer, precondition, path, replaces [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 11 [ 43]: Allow-Events: talk, hold, conference, refer [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 12 [ 49]: Reason: Q.850;cause=3;text="NO_ROUTE_DESTINATION" [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Mar 18 07:38:23] VERBOSE[11932] chan_sip.c: --- (14 headers 0 lines) --- [Mar 18 07:38:23] DEBUG[11932] chan_sip.c: = Looking for Call ID: 0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060 (Checking To) --From tag as4932d8de --To-tag BKBg920c77tcB [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Using Reason header for cause code: 3 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Acked pending invite 102 [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Stopping retransmission on '0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060' of Request 102: Match Found [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: SIP response 404 to standard invite [Mar 18 07:38:23] VERBOSE[11932][C-0000000f] chan_sip.c: Transmitting (no NAT) to 172.25.59.11:5060: ˙ACK sip:61403000000@172.25.59.11:5060 SIP/2.0 ˙Via: SIP/2.0/UDP 172.25.59.250:5060;branch=z9hG4bK64438bc3 ˙Max-Forwards: 70 ˙From: "Nick Adams [Company]" ;tag=as4932d8de ˙To: ;tag=BKBg920c77tcB ˙Contact: ˙Call-ID: 0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060 ˙CSeq: 102 ACK ˙User-Agent: Asterisk PBX 11.8.1 ˙Content-Length: 0 ˙ ˙ ˙--- [Mar 18 07:38:23] DEBUG[11932][C-0000000f] chan_sip.c: Trying to put 'ACK sip:614' onto UDP socket destined for 172.25.59.11:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] channel.c: Hanging up channel 'SIP/172.25.59.11:5060-0000001d' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Hangup call SIP/172.25.59.11:5060-0000001d, SIP callid 0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f9b87e21c78' [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: Scheduling destruction of SIP dialog '0f8985ad5fa487d5365595b55078a01b@172.25.59.250:5060' in 32000 ms (Method: INVITE) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] cdr.c: Dropping CDR ! [Mar 18 07:38:23] DEBUG[4677][C-0000000f] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL. [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Launching 'Hangup' [Mar 18 07:38:23] DEBUG[11921] devicestate.c: No provider found, checking channel drivers for SIP - 172.25.59.11:5060 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] channel.c: Soft-Hanging up channel 'SIP/506-0000001b' [Mar 18 07:38:23] DEBUG[11921] chan_sip.c: Checking device state for peer 172.25.59.11:5060 [Mar 18 07:38:23] DEBUG[11921] devicestate.c: Changing state for SIP/172.25.59.11:5060 - state 4 (Invalid) [Mar 18 07:38:23] DEBUG[11921] devicestate.c: device 'SIP/172.25.59.11:5060' state '4' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Spawn extension (outboundcall,61403000000,2) exited non-zero on 'SIP/506-0000001b' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] channel.c: Soft-Hanging up channel 'SIP/506-0000001b' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] channel.c: Soft-Hanging up channel 'SIP/506-0000001b' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Result of 'EVENTID' is NULL [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Result of 'HANGUPCAUSE' is '1' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Result of 'DIALSTATUS' is 'CHANUNAVAIL' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Launching 'NoOp' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Function CDR(dstchannel) result is 'SIP/NetSIPBrisbane1-0000001c' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Function HASH(SIP_CAUSE,SIP/NetSIPBrisbane1-0000001c) result is '' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Launching 'NoOp' [Mar 18 07:38:23] DEBUG[11943] app_queue.c: Device 'SIP/172.25.59.11:5060' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Result of 'HANGUPCAUSE_STRING' is NULL [Mar 18 07:38:23] DEBUG[4677][C-0000000f] pbx.c: Launching 'NoOp' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] channel.c: Hanging up channel 'SIP/506-0000001b' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Hangup call SIP/506-0000001b, SIP callid 3c30e3708588-qga585hc6now [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: update_call_counter(506) - decrement call limit counter on hangup [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Updating call counter for incoming call [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Call from peer '506' removed from call limit 2147483647 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Hanging up channel in state Ring (not UP) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f9bc00386b8' [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: Scheduling destruction of SIP dialog '3c30e3708588-qga585hc6now' in 6400 ms (Method: INVITE) [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Session timer stopped: 40345 - 3c30e3708588-qga585hc6now [Mar 18 07:38:23] DEBUG[11921] devicestate.c: No provider found, checking channel drivers for SIP - 506 [Mar 18 07:38:23] VERBOSE[4677][C-0000000f] chan_sip.c: ˙<--- Reliably Transmitting (no NAT) to 59.167.211.8:3964 ---> ˙SIP/2.0 404 Not Found ˙Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-0i7ofjt37h97;received=59.167.211.8;rport=3964 ˙From: "Nick Adams [Company]" ;tag=4t4f4q418t ˙To: ;tag=as4aabe939 ˙Call-ID: 3c30e3708588-qga585hc6now ˙CSeq: 2 INVITE ˙Server: Asterisk PBX 11.8.1 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Reason: Q.850;cause=1 ˙Content-Length: 0 ˙ ˙ ˙<------------> [Mar 18 07:38:23] DEBUG[11921] chan_sip.c: Checking device state for peer 506 [Mar 18 07:38:23] DEBUG[11921] devicestate.c: Changing state for SIP/506 - state 1 (Not in use) [Mar 18 07:38:23] DEBUG[11921] devicestate.c: device 'SIP/506' state '1' [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #40353 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 59.167.211.8:3964 [Mar 18 07:38:23] DEBUG[4677][C-0000000f] cdr.c: Dropping CDR ! [Mar 18 07:38:23] DEBUG[11921] devicestate.c: No provider found, checking channel drivers for SIP - 506 [Mar 18 07:38:23] DEBUG[11943] app_queue.c: Device 'SIP/506' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 18 07:38:23] DEBUG[11921] chan_sip.c: Checking device state for peer 506 [Mar 18 07:38:23] DEBUG[11921] devicestate.c: Changing state for SIP/506 - state 1 (Not in use) [Mar 18 07:38:23] DEBUG[11921] devicestate.c: device 'SIP/506' state '1' [Mar 18 07:38:23] DEBUG[11923] app_queue.c: Extension '506@Company-SIP-Handsets' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 18 07:38:23] DEBUG[11943] app_queue.c: Device 'SIP/506' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: SIP TIMER: Rescheduling retransmission #40353 (1) SIP/2.0 - 1 [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 200 ms (t1 100 ms (Retrans id #40353)) [Mar 18 07:38:24] VERBOSE[11932] chan_sip.c: Retransmitting #1 (no NAT) to 59.167.211.8:3964: ˙SIP/2.0 404 Not Found ˙Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-0i7ofjt37h97;received=59.167.211.8;rport=3964 ˙From: "Nick Adams [Company]" ;tag=4t4f4q418t ˙To: ;tag=as4aabe939 ˙Call-ID: 3c30e3708588-qga585hc6now ˙CSeq: 2 INVITE ˙Server: Asterisk PBX 11.8.1 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Reason: Q.850;cause=1 ˙Content-Length: 0 ˙ ˙ ˙--- [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 59.167.211.8:3964 [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: SIP TIMER: Rescheduling retransmission #40353 (2) SIP/2.0 - 1 [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: ** SIP timers: Rescheduling retransmission 3 to 400 ms (t1 100 ms (Retrans id #40353)) [Mar 18 07:38:24] VERBOSE[11932] chan_sip.c: Retransmitting #2 (no NAT) to 59.167.211.8:3964: ˙SIP/2.0 404 Not Found ˙Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-0i7ofjt37h97;received=59.167.211.8;rport=3964 ˙From: "Nick Adams [Company]" ;tag=4t4f4q418t ˙To: ;tag=as4aabe939 ˙Call-ID: 3c30e3708588-qga585hc6now ˙CSeq: 2 INVITE ˙Server: Asterisk PBX 11.8.1 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Reason: Q.850;cause=1 ˙Content-Length: 0 ˙ ˙ ˙--- [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 59.167.211.8:3964 [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: SIP TIMER: Rescheduling retransmission #40353 (3) SIP/2.0 - 1 [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: ** SIP timers: Rescheduling retransmission 4 to 800 ms (t1 100 ms (Retrans id #40353)) [Mar 18 07:38:24] VERBOSE[11932] chan_sip.c: Retransmitting #3 (no NAT) to 59.167.211.8:3964: ˙SIP/2.0 404 Not Found ˙Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-0i7ofjt37h97;received=59.167.211.8;rport=3964 ˙From: "Nick Adams [Company]" ;tag=4t4f4q418t ˙To: ;tag=as4aabe939 ˙Call-ID: 3c30e3708588-qga585hc6now ˙CSeq: 2 INVITE ˙Server: Asterisk PBX 11.8.1 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Reason: Q.850;cause=1 ˙Content-Length: 0 ˙ ˙ ˙--- [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Trying to put 'SIP/2.0 404' onto UDP socket destined for 59.167.211.8:3964 [Mar 18 07:38:24] VERBOSE[11932] chan_sip.c: ˙<--- SIP read from UDP:59.167.211.8:3964 ---> ˙ACK sip:0403000000@bebe.MYDOMAIN.com.au SIP/2.0 ˙Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-0i7ofjt37h97;rport ˙From: "Nick Adams [Company]" ;tag=4t4f4q418t ˙To: ;tag=as4aabe939 ˙Call-ID: 3c30e3708588-qga585hc6now ˙CSeq: 2 ACK ˙Max-Forwards: 70 ˙Contact: ;reg-id=1 ˙Content-Length: 0 ˙ ˙<-------------> [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Header 0 [ 47]: ACK sip:0403000000@bebe.MYDOMAIN.com.au SIP/2.0 [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 59.167.211.8:3964;branch=z9hG4bK-0i7ofjt37h97;rport [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Header 2 [ 75]: From: "Nick Adams [Company]" ;tag=4t4f4q418t [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Header 3 [ 56]: To: ;tag=as4aabe939 [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Header 4 [ 34]: Call-ID: 3c30e3708588-qga585hc6now [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Header 5 [ 11]: CSeq: 2 ACK [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Header 7 [ 59]: Contact: ;reg-id=1 [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Mar 18 07:38:24] VERBOSE[11932] chan_sip.c: --- (9 headers 0 lines) --- [Mar 18 07:38:24] DEBUG[11932] chan_sip.c: = Looking for Call ID: 3c30e3708588-qga585hc6now (Checking From) --From tag 4t4f4q418t --To-tag as4aabe939 [Mar 18 07:38:24] DEBUG[11932][C-0000000f] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Mar 18 07:38:24] DEBUG[11932][C-0000000f] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #40353 [Mar 18 07:38:24] DEBUG[11932][C-0000000f] chan_sip.c: Stopping retransmission on '3c30e3708588-qga585hc6now' of Response 2: Match Found [Mar 18 07:38:28] DEBUG[4678] http.c: HTTP Request URI is /rawman?&action=status [Mar 18 07:38:28] DEBUG[4678] http.c: match request [rawman] with handler [httpstatus] len 0 [Mar 18 07:38:28] DEBUG[4678] http.c: match request [rawman] with handler [phoneprov] len 10 [Mar 18 07:38:28] DEBUG[4678] http.c: match request [rawman] with handler [amanager] len 9 [Mar 18 07:38:28] DEBUG[4678] http.c: match request [rawman] with handler [arawman] len 8 [Mar 18 07:38:28] DEBUG[4678] http.c: match request [rawman] with handler [manager] len 7 [Mar 18 07:38:28] DEBUG[4678] http.c: match request [rawman] with handler [rawman] len 7 [Mar 18 07:38:28] DEBUG[4678] http.c: HTTP Cookie, Name: 'mansession_id' Value: '313632e7' [Mar 18 07:38:28] DEBUG[4678] manager.c: HTTP Manager add header : [Mar 18 07:38:28] DEBUG[4678] manager.c: HTTP Manager add header action: status [Mar 18 07:38:28] DEBUG[4678] manager.c: Running action 'Status' [Mar 18 07:38:30] DEBUG[11932] chan_sip.c: Auto destroying SIP dialog '3c30e3708588-qga585hc6now' [Mar 18 07:38:30] DEBUG[11932] chan_sip.c: Destroying SIP dialog 3c30e3708588-qga585hc6now [Mar 18 07:38:30] VERBOSE[11932] chan_sip.c: Really destroying SIP dialog '3c30e3708588-qga585hc6now' Method: ACK [Mar 18 07:38:30] DEBUG[11932] rtp_engine.c: Destroyed RTP instance '0x7f9bc00386b8' [Mar 18 07:38:33] DEBUG[11932] chan_sip.c: Auto destroying SIP dialog '3c30e0e0651c-97jds01iq3df' [Mar 18 07:38:33] DEBUG[11932] chan_sip.c: Destroying SIP dialog 3c30e0e0651c-97jds01iq3df [Mar 18 07:38:33] DEBUG[4679] http.c: HTTP Request URI is /rawman?&action=status [Mar 18 07:38:33] DEBUG[4679] http.c: match request [rawman] with handler [httpstatus] len 0 [Mar 18 07:38:33] DEBUG[4679] http.c: match request [rawman] with handler [phoneprov] len 10 [Mar 18 07:38:33] DEBUG[4679] http.c: match request [rawman] with handler [amanager] len 9 [Mar 18 07:38:33] DEBUG[4679] http.c: match request [rawman] with handler [arawman] len 8 [Mar 18 07:38:33] DEBUG[4679] http.c: match request [rawman] with handler [manager] len 7 [Mar 18 07:38:33] DEBUG[4679] http.c: match request [rawman] with handler [rawman] len 7