[Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Scheduled a registration timeout for voip.pocos.nl id #2099366 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: >>> Re-using Auth data for officevoiptrunk@voip.pocos.nl [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Initializing initreq for method REGISTER - callid 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 0 [ 34]: REGISTER sip:voip.pocos.nl SIP/2.0 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK5a405b2d;rport [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 3 [ 56]: From: ;tag=as06a2a60e [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 4 [ 39]: To: [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 5 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 6 [ 19]: CSeq: 3232 REGISTER [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 7 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 8 [169]: Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="7ef9c9be", response="700ae6868a6e19af4d9e0fee8f2f327d" [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 10 [ 51]: Contact: [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jun 25 13:40:38] VERBOSE[3581] chan_sip.c: REGISTER 12 headers, 0 lines [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: REGISTER attempt 1 to officevoiptrunk@voip.pocos.nl [Jun 25 13:40:38] VERBOSE[3581] chan_sip.c: Reliably Transmitting (NAT) to 109.235.32.36:5060: REGISTER sip:voip.pocos.nl SIP/2.0 Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK5a405b2d;rport Max-Forwards: 70 From: ;tag=as06a2a60e To: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 CSeq: 3232 REGISTER User-Agent: Asterisk PBX 1.6.2.6-1 Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="7ef9c9be", response="700ae6868a6e19af4d9e0fee8f2f327d" Expires: 120 Contact: Content-Length: 0 --- [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 0 [ 34]: REGISTER sip:voip.pocos.nl SIP/2.0 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK5a405b2d;rport [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 3 [ 56]: From: ;tag=as06a2a60e [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 4 [ 39]: To: [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 5 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 6 [ 19]: CSeq: 3232 REGISTER [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 7 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 8 [169]: Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="7ef9c9be", response="700ae6868a6e19af4d9e0fee8f2f327d" [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 10 [ 51]: Contact: [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Header 12 [ 0]: [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: Trying to put 'REGISTER si' onto TCP socket destined for 109.235.32.36:5060 [Jun 25 13:40:38] DEBUG[3581] chan_sip.c: SIP Registry voip.pocos.nl: refcount now 3 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 0 [ 24]: SIP/2.0 401 Unauthorized [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 1 [ 91]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK5a405b2d;received=88.159.8.123;rport=37115 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 2 [ 56]: From: ;tag=as06a2a60e [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 3 [ 54]: To: ;tag=as1478dcce [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 4 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 5 [ 19]: CSeq: 3232 REGISTER [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 9 [ 74]: WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1b55c60d" [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 11 [ 0]: [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: <--- SIP read from TCP:109.235.32.36:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK5a405b2d;received=88.159.8.123;rport=37115 From: ;tag=as06a2a60e To: ;tag=as1478dcce Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 CSeq: 3232 REGISTER Server: Asterisk PBX 1.6.2.6-1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1b55c60d" Content-Length: 0 <-------------> [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 0 [ 24]: SIP/2.0 401 Unauthorized [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 1 [ 91]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK5a405b2d;received=88.159.8.123;rport=37115 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 2 [ 56]: From: ;tag=as06a2a60e [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 3 [ 54]: To: ;tag=as1478dcce [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 4 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 5 [ 19]: CSeq: 3232 REGISTER [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 9 [ 74]: WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1b55c60d" [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 11 [ 0]: [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: --- (11 headers 0 lines) --- [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: Responding to challenge, registration to domain/host name voip.pocos.nl [Jun 25 13:40:38] VERBOSE[18340] dnsmgr.c: > doing dnsmgr_lookup for 'voip.pocos.nl' [Jun 25 13:40:38] VERBOSE[18340] srv.c: > ast_get_srv: SRV lookup for '_sip._TCP.voip.pocos.nl' mapped to host voip.pocos.nl, port 5060 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Initializing already initialized SIP dialog 2c34822309cf76687f5224096e56ffbf@127.0.1.1 (presumably reinvite) [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 0 [ 34]: REGISTER sip:voip.pocos.nl SIP/2.0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK4916ccc1;rport [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 3 [ 56]: From: ;tag=as53c14dd6 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 4 [ 39]: To: [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 5 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 6 [ 19]: CSeq: 3233 REGISTER [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 7 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 8 [169]: Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="1b55c60d", response="acfe7c84ef76bdbc6e7a9eaa980facf2" [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 10 [ 51]: Contact: [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: REGISTER 12 headers, 0 lines [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: REGISTER attempt 2 to officevoiptrunk@voip.pocos.nl [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: Reliably Transmitting (NAT) to 109.235.32.36:5060: REGISTER sip:voip.pocos.nl SIP/2.0 Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK4916ccc1;rport Max-Forwards: 70 From: ;tag=as53c14dd6 To: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 CSeq: 3233 REGISTER User-Agent: Asterisk PBX 1.6.2.6-1 Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="1b55c60d", response="acfe7c84ef76bdbc6e7a9eaa980facf2" Expires: 120 Contact: Content-Length: 0 --- [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 0 [ 34]: REGISTER sip:voip.pocos.nl SIP/2.0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK4916ccc1;rport [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 3 [ 56]: From: ;tag=as53c14dd6 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 4 [ 39]: To: [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 5 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 6 [ 19]: CSeq: 3233 REGISTER [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 7 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 8 [169]: Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="1b55c60d", response="acfe7c84ef76bdbc6e7a9eaa980facf2" [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 10 [ 51]: Contact: [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 12 [ 0]: [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Trying to put 'REGISTER si' onto TCP socket destined for 109.235.32.36:5060 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 0 [ 56]: OPTIONS sip:voiptrunk@88.159.8.123;transport=TCP SIP/2.0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK5a85892f;rport [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as4a7867b2 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 4 [ 46]: To: [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 5 [ 51]: Contact: [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 6 [ 55]: Call-ID: 560bf55a0bb8cf0f473465f95f12bc36@109.235.32.36 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 8 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 9 [ 35]: Date: Fri, 25 Jun 2010 11:40:38 GMT [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 13 [ 0]: [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: <--- SIP read from TCP:109.235.32.36:5060 ---> OPTIONS sip:voiptrunk@88.159.8.123;transport=TCP SIP/2.0 Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK5a85892f;rport Max-Forwards: 70 From: "asterisk" ;tag=as4a7867b2 To: Contact: Call-ID: 560bf55a0bb8cf0f473465f95f12bc36@109.235.32.36 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.6-1 Date: Fri, 25 Jun 2010 11:40:38 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <-------------> [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 0 [ 56]: OPTIONS sip:voiptrunk@88.159.8.123;transport=TCP SIP/2.0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK5a85892f;rport [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as4a7867b2 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 4 [ 46]: To: [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 5 [ 51]: Contact: [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 6 [ 55]: Call-ID: 560bf55a0bb8cf0f473465f95f12bc36@109.235.32.36 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 8 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 9 [ 35]: Date: Fri, 25 Jun 2010 11:40:38 GMT [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 13 [ 0]: [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: --- (13 headers 0 lines) --- [Jun 25 13:40:38] DEBUG[18340] acl.c: Found IP address for this socket [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Setting SIP_TRANSPORT_TCP with address 88.159.8.123:5060 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Allocating new SIP dialog for 560bf55a0bb8cf0f473465f95f12bc36@109.235.32.36 - OPTIONS (No RTP) [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: Looking for voiptrunk in invalid (domain 88.159.8.123) [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: <--- Transmitting (NAT) to 109.235.32.36:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK5a85892f;received=109.235.32.36;rport=5060 From: "asterisk" ;tag=as4a7867b2 To: ;tag=as7859e402 Call-ID: 560bf55a0bb8cf0f473465f95f12bc36@109.235.32.36 CSeq: 102 OPTIONS Server: Asterisk PBX 1.6.2.6-1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Accept: application/sdp Content-Length: 0 <------------> [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 0 [ 21]: SIP/2.0 404 Not Found [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK5a85892f;received=109.235.32.36;rport=5060 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 2 [ 60]: From: "asterisk" ;tag=as4a7867b2 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 3 [ 61]: To: ;tag=as7859e402 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 4 [ 55]: Call-ID: 560bf55a0bb8cf0f473465f95f12bc36@109.235.32.36 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 9 [ 23]: Accept: application/sdp [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 11 [ 0]: [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Trying to put 'SIP/2.0 404' onto TCP socket destined for 109.235.32.36:5060 [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: Scheduling destruction of SIP dialog '560bf55a0bb8cf0f473465f95f12bc36@109.235.32.36' in 32000 ms (Method: OPTIONS) [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: SIP message could not be handled, bad request: 560bf55a0bb8cf0f473465f95f12bc36@109.235.32.36 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 1 [ 91]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK4916ccc1;received=88.159.8.123;rport=37115 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 2 [ 56]: From: ;tag=as53c14dd6 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 3 [ 54]: To: ;tag=as1478dcce [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 4 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 5 [ 19]: CSeq: 3233 REGISTER [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 10 [ 63]: Contact: ;expires=120 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 11 [ 35]: Date: Fri, 25 Jun 2010 11:40:38 GMT [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 13 [ 0]: [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: <--- SIP read from TCP:109.235.32.36:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK4916ccc1;received=88.159.8.123;rport=37115 From: ;tag=as53c14dd6 To: ;tag=as1478dcce Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 CSeq: 3233 REGISTER Server: Asterisk PBX 1.6.2.6-1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Expires: 120 Contact: ;expires=120 Date: Fri, 25 Jun 2010 11:40:38 GMT Content-Length: 0 <-------------> [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 1 [ 91]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK4916ccc1;received=88.159.8.123;rport=37115 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 2 [ 56]: From: ;tag=as53c14dd6 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 3 [ 54]: To: ;tag=as1478dcce [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 4 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 5 [ 19]: CSeq: 3233 REGISTER [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 10 [ 63]: Contact: ;expires=120 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 11 [ 35]: Date: Fri, 25 Jun 2010 11:40:38 GMT [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Header 13 [ 0]: [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: --- (13 headers 0 lines) --- [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Registration successful [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: Cancelling timeout 2099366 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: SIP Registry voip.pocos.nl: refcount now 2 [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: SIP Registry voip.pocos.nl: refcount now 1 [Jun 25 13:40:38] VERBOSE[18340] chan_sip.c: Scheduling destruction of SIP dialog '2c34822309cf76687f5224096e56ffbf@127.0.1.1' in 32000 ms (Method: REGISTER) [Jun 25 13:40:38] NOTICE[18340] chan_sip.c: Outbound Registration: Expiry for voip.pocos.nl is 120 sec (Scheduling reregistration in 105 s) [Jun 25 13:40:38] DEBUG[18340] chan_sip.c: SIP Registry voip.pocos.nl: refcount now 2 ------------------------------------------------------------ [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 0 [ 42]: INVITE sip:0880100707@88.159.8.123 SIP/2.0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK4f325e30;rport [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 3 [ 62]: From: "881004040" ;tag=as7ac96ec8 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 4 [ 33]: To: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 5 [ 52]: Contact: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 6 [ 55]: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 8 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 9 [ 35]: Date: Fri, 25 Jun 2010 11:42:47 GMT [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 13 [ 19]: Content-Length: 211 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 14 [ 0]: [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: <--- SIP read from TCP:109.235.32.36:5060 ---> INVITE sip:0880100707@88.159.8.123 SIP/2.0 Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK4f325e30;rport Max-Forwards: 70 From: "881004040" ;tag=as7ac96ec8 To: Contact: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.2.6-1 Date: Fri, 25 Jun 2010 11:42:47 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 211 v=0 o=root 1710170764 1710170764 IN IP4 109.235.32.36 s=Asterisk PBX 1.6.2.6-1 c=IN IP4 109.235.32.36 t=0 0 m=audio 16252 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 0 [ 42]: INVITE sip:0880100707@88.159.8.123 SIP/2.0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK4f325e30;rport [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 3 [ 62]: From: "881004040" ;tag=as7ac96ec8 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 4 [ 33]: To: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 5 [ 52]: Contact: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 6 [ 55]: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 8 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 9 [ 35]: Date: Fri, 25 Jun 2010 11:42:47 GMT [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 13 [ 19]: Content-Length: 211 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 14 [ 0]: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 0 [ 3]: v=0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 1 [ 49]: o=root 1710170764 1710170764 IN IP4 109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 2 [ 24]: s=Asterisk PBX 1.6.2.6-1 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 3 [ 22]: c=IN IP4 109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 4 [ 5]: t=0 0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 5 [ 23]: m=audio 16252 RTP/AVP 8 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 7 [ 25]: a=silenceSupp:off - - - - [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 8 [ 10]: a=ptime:20 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 9 [ 10]: a=sendrecv [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: --- (14 headers 10 lines) --- [Jun 25 13:42:47] DEBUG[18340] acl.c: Found IP address for this socket [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Setting SIP_TRANSPORT_TCP with address 88.159.8.123:5060 [Jun 25 13:42:47] VERBOSE[18340] netsock.c: == Using SIP RTP CoS mark 5 [Jun 25 13:42:47] VERBOSE[18340] netsock.c: == Using SIP VRTP CoS mark 6 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Setting NAT on RTP to On [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Setting NAT on VRTP to On [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Allocating new SIP dialog for 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 - INVITE (With RTP) [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Begin: parsing SIP "Supported: replaces, timer" [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Found SIP option: -replaces- [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Matched SIP option: replaces [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Found SIP option: -timer- [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Matched SIP option: timer [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Sending to 109.235.32.36 : 5060 (NAT) [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Initializing initreq for method INVITE - callid 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Using INVITE request as basis request - 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Found peer 'officevoiptrunk' for '881004040' from 109.235.32.36:5060 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Setting NAT on RTP to On [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Setting NAT on VRTP to On [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: <--- Reliably Transmitting (NAT) to 109.235.32.36:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK4f325e30;received=109.235.32.36;rport=5060 From: "881004040" ;tag=as7ac96ec8 To: ;tag=as091708fe Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 CSeq: 102 INVITE Server: Asterisk PBX 1.6.2.6-1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="729d9978" Content-Length: 0 <------------> [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 0 [ 24]: SIP/2.0 401 Unauthorized [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK4f325e30;received=109.235.32.36;rport=5060 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 2 [ 62]: From: "881004040" ;tag=as7ac96ec8 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 3 [ 48]: To: ;tag=as091708fe [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 4 [ 55]: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 9 [ 74]: WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="729d9978" [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 11 [ 0]: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Trying to put 'SIP/2.0 401' onto TCP socket destined for 109.235.32.36:5060 [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Scheduling destruction of SIP dialog '1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36' in 6400 ms (Method: INVITE) [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 0 [ 39]: ACK sip:0880100707@88.159.8.123 SIP/2.0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK4f325e30;rport [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 3 [ 62]: From: "881004040" ;tag=as7ac96ec8 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 4 [ 48]: To: ;tag=as091708fe [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 5 [ 52]: Contact: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 6 [ 55]: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 7 [ 13]: CSeq: 102 ACK [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 8 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 10 [ 0]: [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: <--- SIP read from TCP:109.235.32.36:5060 ---> ACK sip:0880100707@88.159.8.123 SIP/2.0 Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK4f325e30;rport Max-Forwards: 70 From: "881004040" ;tag=as7ac96ec8 To: ;tag=as091708fe Contact: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.2.6-1 Content-Length: 0 <-------------> [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 0 [ 39]: ACK sip:0880100707@88.159.8.123 SIP/2.0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK4f325e30;rport [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 3 [ 62]: From: "881004040" ;tag=as7ac96ec8 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 4 [ 48]: To: ;tag=as091708fe [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 5 [ 52]: Contact: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 6 [ 55]: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 7 [ 13]: CSeq: 102 ACK [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 8 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 10 [ 0]: [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: --- (10 headers 0 lines) --- [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Stopping retransmission on '1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36' of Response 102: Match Not Found [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 0 [ 42]: INVITE sip:0880100707@88.159.8.123 SIP/2.0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK222828fc;rport [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 3 [ 62]: From: "881004040" ;tag=as7ac96ec8 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 4 [ 33]: To: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 5 [ 52]: Contact: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 6 [ 55]: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 7 [ 16]: CSeq: 103 INVITE [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 8 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 9 [179]: Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:0880100707@88.159.8.123", nonce="729d9978", response="8bcba7ff752bada984915a92d9b8480f" [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 10 [ 35]: Date: Fri, 25 Jun 2010 11:42:47 GMT [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 11 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 12 [ 26]: Supported: replaces, timer [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 14 [ 19]: Content-Length: 211 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 15 [ 0]: [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: <--- SIP read from TCP:109.235.32.36:5060 ---> INVITE sip:0880100707@88.159.8.123 SIP/2.0 Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK222828fc;rport Max-Forwards: 70 From: "881004040" ;tag=as7ac96ec8 To: Contact: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 CSeq: 103 INVITE User-Agent: Asterisk PBX 1.6.2.6-1 Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:0880100707@88.159.8.123", nonce="729d9978", response="8bcba7ff752bada984915a92d9b8480f" Date: Fri, 25 Jun 2010 11:42:47 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 211 v=0 o=root 1710170764 1710170765 IN IP4 109.235.32.36 s=Asterisk PBX 1.6.2.6-1 c=IN IP4 109.235.32.36 t=0 0 m=audio 16252 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 0 [ 42]: INVITE sip:0880100707@88.159.8.123 SIP/2.0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK222828fc;rport [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 3 [ 62]: From: "881004040" ;tag=as7ac96ec8 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 4 [ 33]: To: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 5 [ 52]: Contact: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 6 [ 55]: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 7 [ 16]: CSeq: 103 INVITE [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 8 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 9 [179]: Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:0880100707@88.159.8.123", nonce="729d9978", response="8bcba7ff752bada984915a92d9b8480f" [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 10 [ 35]: Date: Fri, 25 Jun 2010 11:42:47 GMT [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 11 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 12 [ 26]: Supported: replaces, timer [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 14 [ 19]: Content-Length: 211 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 15 [ 0]: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 0 [ 3]: v=0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 1 [ 49]: o=root 1710170764 1710170765 IN IP4 109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 2 [ 24]: s=Asterisk PBX 1.6.2.6-1 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 3 [ 22]: c=IN IP4 109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 4 [ 5]: t=0 0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 5 [ 23]: m=audio 16252 RTP/AVP 8 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 7 [ 25]: a=silenceSupp:off - - - - [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 8 [ 10]: a=ptime:20 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Body 9 [ 10]: a=sendrecv [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: --- (15 headers 10 lines) --- [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Sending to 109.235.32.36 : 5060 (NAT) [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Initializing initreq for method INVITE - callid 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Using INVITE request as basis request - 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Found peer 'officevoiptrunk' for '881004040' from 109.235.32.36:5060 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Setting NAT on RTP to On [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Setting NAT on VRTP to On [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Processing session-level SDP o=root 1710170764 1710170765 IN IP4 109.235.32.36... UNSUPPORTED. [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Processing session-level SDP s=Asterisk PBX 1.6.2.6-1... UNSUPPORTED. [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Processing session-level SDP c=IN IP4 109.235.32.36... OK. [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Found RTP audio format 8 [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Found audio description format PCMA for ID 8 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED. [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Capabilities: us - 0x908 (alaw|g726|g729), peer - audio=0x8 (alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw) [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Non-codec capabilities (dtmf): us - 0x0 (nothing), peer - 0x0 (nothing), combined - 0x0 (nothing) [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Peer audio RTP is at port 109.235.32.36:16252 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Checking SIP call limits for device officevoiptrunk [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Updating call counter for incoming call [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: Looking for 0880100707 in voiptrunk (domain 88.159.8.123) [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: *** Our native formats are 0x8 (alaw) [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: *** Our capabilities are 0x908 (alaw|g726|g729) [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: This channel will not be able to handle video. [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: build_route: Contact hop: [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: list_route: hop: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Incoming INVITE with 'timer' option enabled [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Session timer started: 2099591 - 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: SIP/officevoiptrunk-00001338: New call is still down.... Trying... [Jun 25 13:42:47] VERBOSE[18340] chan_sip.c: <--- Transmitting (NAT) to 109.235.32.36:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK222828fc;received=109.235.32.36;rport=5060 From: "881004040" ;tag=as7ac96ec8 To: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 CSeq: 103 INVITE Server: Asterisk PBX 1.6.2.6-1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Length: 0 <------------> [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK222828fc;received=109.235.32.36;rport=5060 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 2 [ 62]: From: "881004040" ;tag=as7ac96ec8 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 3 [ 33]: To: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 4 [ 55]: Call-ID: 1a0e049415f6bfe36641bf8a0399edb0@109.235.32.36 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 5 [ 16]: CSeq: 103 INVITE [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 9 [ 14]: Require: timer [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 11 [ 52]: Contact: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Header 13 [ 0]: [Jun 25 13:42:47] DEBUG[18340] chan_sip.c: Trying to put 'SIP/2.0 100' onto TCP socket destined for 109.235.32.36:5060 ------------------------------------------------------------ [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Acked pending invite 1641 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2100381 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Stopping retransmission on '8b0ea4da476d8bf1' of Request 1641: Match Found [Jun 25 13:50:43] VERBOSE[3581] chan_sip.c: SIP Response message for INCOMING dialog NOTIFY arrived [Jun 25 13:50:43] NOTICE[3581] chan_sip.c: -- Re-registration for officevoiptrunk@voip.pocos.nl [Jun 25 13:50:43] VERBOSE[3581] dnsmgr.c: > doing dnsmgr_lookup for 'voip.pocos.nl' [Jun 25 13:50:43] DEBUG[12666] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=85) [Jun 25 13:50:43] VERBOSE[3581] srv.c: > ast_get_srv: SRV lookup for '_sip._TCP.voip.pocos.nl' mapped to host voip.pocos.nl, port 5060 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Allocating new SIP dialog for 2c34822309cf76687f5224096e56ffbf@127.0.1.1 - REGISTER (No RTP) [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: SIP Registry voip.pocos.nl: refcount now 3 [Jun 25 13:50:43] DEBUG[3581] acl.c: Found IP address for this socket [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Setting SIP_TRANSPORT_TCP with address 88.159.8.123:5060 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: SIP Registry voip.pocos.nl: refcount now 4 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Scheduled a registration timeout for voip.pocos.nl id #2100384 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: >>> Re-using Auth data for officevoiptrunk@voip.pocos.nl [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Initializing initreq for method REGISTER - callid 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 0 [ 34]: REGISTER sip:voip.pocos.nl SIP/2.0 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK64437cb7;rport [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 3 [ 56]: From: ;tag=as6d6f1214 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 4 [ 39]: To: [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 5 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 6 [ 19]: CSeq: 3234 REGISTER [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 7 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 8 [169]: Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="1b55c60d", response="acfe7c84ef76bdbc6e7a9eaa980facf2" [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 10 [ 51]: Contact: [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jun 25 13:50:43] VERBOSE[3581] chan_sip.c: REGISTER 12 headers, 0 lines [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: REGISTER attempt 1 to officevoiptrunk@voip.pocos.nl [Jun 25 13:50:43] VERBOSE[3581] chan_sip.c: Reliably Transmitting (NAT) to 109.235.32.36:5060: REGISTER sip:voip.pocos.nl SIP/2.0 Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK64437cb7;rport Max-Forwards: 70 From: ;tag=as6d6f1214 To: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 CSeq: 3234 REGISTER User-Agent: Asterisk PBX 1.6.2.6-1 Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="1b55c60d", response="acfe7c84ef76bdbc6e7a9eaa980facf2" Expires: 120 Contact: Content-Length: 0 --- [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 0 [ 34]: REGISTER sip:voip.pocos.nl SIP/2.0 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK64437cb7;rport [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 3 [ 56]: From: ;tag=as6d6f1214 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 4 [ 39]: To: [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 5 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 6 [ 19]: CSeq: 3234 REGISTER [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 7 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 8 [169]: Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="1b55c60d", response="acfe7c84ef76bdbc6e7a9eaa980facf2" [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 10 [ 51]: Contact: [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Header 12 [ 0]: [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Trying to put 'REGISTER si' onto TCP socket destined for 109.235.32.36:5060 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: SIP Registry voip.pocos.nl: refcount now 3 [Jun 25 13:50:43] DEBUG[3581] chan_sip.c: Destroying SIP dialog 2e10a93308a5386a16300ce079d5d251@88.159.8.123 [Jun 25 13:50:43] VERBOSE[3581] chan_sip.c: Really destroying SIP dialog '2e10a93308a5386a16300ce079d5d251@88.159.8.123' Method: OPTIONS [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 0 [ 24]: SIP/2.0 401 Unauthorized [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 1 [ 91]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK64437cb7;received=88.159.8.123;rport=37115 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 2 [ 56]: From: ;tag=as6d6f1214 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 3 [ 54]: To: ;tag=as5ef08a0d [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 4 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 5 [ 19]: CSeq: 3234 REGISTER [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 9 [ 74]: WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="77060136" [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 11 [ 0]: [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: <--- SIP read from TCP:109.235.32.36:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK64437cb7;received=88.159.8.123;rport=37115 From: ;tag=as6d6f1214 To: ;tag=as5ef08a0d Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 CSeq: 3234 REGISTER Server: Asterisk PBX 1.6.2.6-1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="77060136" Content-Length: 0 <-------------> [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 0 [ 24]: SIP/2.0 401 Unauthorized [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 1 [ 91]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK64437cb7;received=88.159.8.123;rport=37115 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 2 [ 56]: From: ;tag=as6d6f1214 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 3 [ 54]: To: ;tag=as5ef08a0d [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 4 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 5 [ 19]: CSeq: 3234 REGISTER [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 9 [ 74]: WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="77060136" [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 11 [ 0]: [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: --- (11 headers 0 lines) --- [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: Responding to challenge, registration to domain/host name voip.pocos.nl [Jun 25 13:50:43] VERBOSE[18340] dnsmgr.c: > doing dnsmgr_lookup for 'voip.pocos.nl' [Jun 25 13:50:43] VERBOSE[18340] srv.c: > ast_get_srv: SRV lookup for '_sip._TCP.voip.pocos.nl' mapped to host voip.pocos.nl, port 5060 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Initializing already initialized SIP dialog 2c34822309cf76687f5224096e56ffbf@127.0.1.1 (presumably reinvite) [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 0 [ 34]: REGISTER sip:voip.pocos.nl SIP/2.0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK109ff9be;rport [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 3 [ 56]: From: ;tag=as3a76668b [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 4 [ 39]: To: [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 5 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 6 [ 19]: CSeq: 3235 REGISTER [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 7 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 8 [169]: Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="77060136", response="e86989bafbb98a30a24d35e20201b854" [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 10 [ 51]: Contact: [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: REGISTER 12 headers, 0 lines [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: REGISTER attempt 2 to officevoiptrunk@voip.pocos.nl [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: Reliably Transmitting (NAT) to 109.235.32.36:5060: REGISTER sip:voip.pocos.nl SIP/2.0 Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK109ff9be;rport Max-Forwards: 70 From: ;tag=as3a76668b To: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 CSeq: 3235 REGISTER User-Agent: Asterisk PBX 1.6.2.6-1 Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="77060136", response="e86989bafbb98a30a24d35e20201b854" Expires: 120 Contact: Content-Length: 0 --- [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 0 [ 34]: REGISTER sip:voip.pocos.nl SIP/2.0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK109ff9be;rport [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 3 [ 56]: From: ;tag=as3a76668b [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 4 [ 39]: To: [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 5 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 6 [ 19]: CSeq: 3235 REGISTER [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 7 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 8 [169]: Authorization: Digest username="officevoiptrunk", realm="asterisk", algorithm=MD5, uri="sip:voip.pocos.nl", nonce="77060136", response="e86989bafbb98a30a24d35e20201b854" [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 10 [ 51]: Contact: [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 12 [ 0]: [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Trying to put 'REGISTER si' onto TCP socket destined for 109.235.32.36:5060 [Jun 25 13:50:43] DEBUG[12666] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=85) [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 0 [ 56]: OPTIONS sip:voiptrunk@88.159.8.123;transport=TCP SIP/2.0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK57c35441;rport [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as47c764c0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 4 [ 46]: To: [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 5 [ 51]: Contact: [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 6 [ 55]: Call-ID: 3075128d6672aaf3359e52e7511cc9e6@109.235.32.36 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 8 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 9 [ 35]: Date: Fri, 25 Jun 2010 11:50:43 GMT [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 13 [ 0]: [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: <--- SIP read from TCP:109.235.32.36:5060 ---> OPTIONS sip:voiptrunk@88.159.8.123;transport=TCP SIP/2.0 Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK57c35441;rport Max-Forwards: 70 From: "asterisk" ;tag=as47c764c0 To: Contact: Call-ID: 3075128d6672aaf3359e52e7511cc9e6@109.235.32.36 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.6-1 Date: Fri, 25 Jun 2010 11:50:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <-------------> [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 0 [ 56]: OPTIONS sip:voiptrunk@88.159.8.123;transport=TCP SIP/2.0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK57c35441;rport [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as47c764c0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 4 [ 46]: To: [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 5 [ 51]: Contact: [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 6 [ 55]: Call-ID: 3075128d6672aaf3359e52e7511cc9e6@109.235.32.36 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 8 [ 34]: User-Agent: Asterisk PBX 1.6.2.6-1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 9 [ 35]: Date: Fri, 25 Jun 2010 11:50:43 GMT [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 13 [ 0]: [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: --- (13 headers 0 lines) --- [Jun 25 13:50:43] DEBUG[18340] acl.c: Found IP address for this socket [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Setting SIP_TRANSPORT_TCP with address 88.159.8.123:5060 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Allocating new SIP dialog for 3075128d6672aaf3359e52e7511cc9e6@109.235.32.36 - OPTIONS (No RTP) [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: Looking for voiptrunk in invalid (domain 88.159.8.123) [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: <--- Transmitting (NAT) to 109.235.32.36:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK57c35441;received=109.235.32.36;rport=5060 From: "asterisk" ;tag=as47c764c0 To: ;tag=as315bfea7 Call-ID: 3075128d6672aaf3359e52e7511cc9e6@109.235.32.36 CSeq: 102 OPTIONS Server: Asterisk PBX 1.6.2.6-1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Accept: application/sdp Content-Length: 0 <------------> [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 0 [ 21]: SIP/2.0 404 Not Found [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 1 [ 92]: Via: SIP/2.0/TCP 109.235.32.36:5060;branch=z9hG4bK57c35441;received=109.235.32.36;rport=5060 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 2 [ 60]: From: "asterisk" ;tag=as47c764c0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 3 [ 61]: To: ;tag=as315bfea7 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 4 [ 55]: Call-ID: 3075128d6672aaf3359e52e7511cc9e6@109.235.32.36 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 9 [ 23]: Accept: application/sdp [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 11 [ 0]: [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Trying to put 'SIP/2.0 404' onto TCP socket destined for 109.235.32.36:5060 [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: Scheduling destruction of SIP dialog '3075128d6672aaf3359e52e7511cc9e6@109.235.32.36' in 32000 ms (Method: OPTIONS) [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: SIP message could not be handled, bad request: 3075128d6672aaf3359e52e7511cc9e6@109.235.32.36 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 1 [ 91]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK109ff9be;received=88.159.8.123;rport=37115 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 2 [ 56]: From: ;tag=as3a76668b [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 3 [ 54]: To: ;tag=as5ef08a0d [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 4 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 5 [ 19]: CSeq: 3235 REGISTER [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 10 [ 63]: Contact: ;expires=120 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 11 [ 35]: Date: Fri, 25 Jun 2010 11:50:43 GMT [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 13 [ 0]: [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: <--- SIP read from TCP:109.235.32.36:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK109ff9be;received=88.159.8.123;rport=37115 From: ;tag=as3a76668b To: ;tag=as5ef08a0d Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 CSeq: 3235 REGISTER Server: Asterisk PBX 1.6.2.6-1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Expires: 120 Contact: ;expires=120 Date: Fri, 25 Jun 2010 11:50:43 GMT Content-Length: 0 <-------------> [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 1 [ 91]: Via: SIP/2.0/TCP 88.159.8.123:5060;branch=z9hG4bK109ff9be;received=88.159.8.123;rport=37115 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 2 [ 56]: From: ;tag=as3a76668b [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 3 [ 54]: To: ;tag=as5ef08a0d [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 4 [ 51]: Call-ID: 2c34822309cf76687f5224096e56ffbf@127.0.1.1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 5 [ 19]: CSeq: 3235 REGISTER [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 6 [ 30]: Server: Asterisk PBX 1.6.2.6-1 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 9 [ 12]: Expires: 120 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 10 [ 63]: Contact: ;expires=120 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 11 [ 35]: Date: Fri, 25 Jun 2010 11:50:43 GMT [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Header 13 [ 0]: [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: --- (13 headers 0 lines) --- [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Registration successful [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: Cancelling timeout 2100384 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: SIP Registry voip.pocos.nl: refcount now 2 [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: SIP Registry voip.pocos.nl: refcount now 1 [Jun 25 13:50:43] VERBOSE[18340] chan_sip.c: Scheduling destruction of SIP dialog '2c34822309cf76687f5224096e56ffbf@127.0.1.1' in 32000 ms (Method: REGISTER) [Jun 25 13:50:43] NOTICE[18340] chan_sip.c: Outbound Registration: Expiry for voip.pocos.nl is 120 sec (Scheduling reregistration in 105 s) [Jun 25 13:50:43] DEBUG[18340] chan_sip.c: SIP Registry voip.pocos.nl: refcount now 2