[2013-10-18 10:37:48] VERBOSE[9914] config.c: == Parsing '/etc/asterisk/logger.conf': [2013-10-18 10:37:48] DEBUG[9914] config.c: Parsing /etc/asterisk/logger.conf [2013-10-18 10:37:48] VERBOSE[9914] config.c: == Found [2013-10-18 10:37:48] VERBOSE[9914] logger.c: Asterisk Queue Logger restarted [2013-10-18 10:38:00] DEBUG[3380] chan_sip.c: Auto destroying SIP dialog 'NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ.' [2013-10-18 10:38:00] DEBUG[3380] chan_sip.c: Destroying SIP dialog NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. [2013-10-18 10:38:00] VERBOSE[3380] chan_sip.c: Really destroying SIP dialog 'NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ.' Method: REGISTER [2013-10-18 10:38:03] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:200.81.44.95:59671 ---> <-------------> [2013-10-18 10:38:03] DEBUG[3380] chan_sip.c: Header 0 [ 0]: [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:86.183.229.226:5060 ---> REGISTER sip:190.220.68.151:14000 SIP/2.0 Via: SIP/2.0/UDP 86.183.229.226:5060;branch=z9hG4bK49492ca915d4a6d7 From: "2005" ;tag=b2692681f68ef594 To: Contact: Supported: path Authorization: Digest username="2005", realm="asterisk", algorithm=MD5, uri="sip:190.220.68.151:14000", nonce="1ea15f49", response="6481d1072b5453b0ee3ea1d54c41c05b" Call-ID: 9836c9e3a3f1f4f4@192.168.1.64 CSeq: 12987 REGISTER Expires: 600 User-Agent: Grandstream BT200 1.1.6.16 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Content-Length: 0 <-------------> [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 0 [ 41]: REGISTER sip:190.220.68.151:14000 SIP/2.0 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 1 [ 67]: Via: SIP/2.0/UDP 86.183.229.226:5060;branch=z9hG4bK49492ca915d4a6d7 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 2 [ 65]: From: "2005" ;tag=b2692681f68ef594 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 3 [ 35]: To: [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 4 [ 53]: Contact: [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 5 [ 15]: Supported: path [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 6 [165]: Authorization: Digest username="2005", realm="asterisk", algorithm=MD5, uri="sip:190.220.68.151:14000", nonce="1ea15f49", response="6481d1072b5453b0ee3ea1d54c41c05b" [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 7 [ 38]: Call-ID: 9836c9e3a3f1f4f4@192.168.1.64 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 8 [ 20]: CSeq: 12987 REGISTER [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 9 [ 12]: Expires: 600 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 10 [ 38]: User-Agent: Grandstream BT200 1.1.6.16 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 11 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 12 [ 77]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: --- (14 headers 0 lines) --- [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: = Looking for Call ID: 9836c9e3a3f1f4f4@192.168.1.64 (Checking From) --From tag b2692681f68ef594 --To-tag [2013-10-18 10:38:05] DEBUG[3380] acl.c: For destination '86.183.229.226', our source address is '192.168.3.50'. [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Target address 86.183.229.226:5060 is not local, substituting externaddr [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 190.220.68.151:14000 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 9836c9e3a3f1f4f4@192.168.1.64 - REGISTER (No RTP) [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Initializing initreq for method REGISTER - callid 9836c9e3a3f1f4f4@192.168.1.64 [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: Splitting '86.183.229.226:5060' into... [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: ...host '86.183.229.226' and port '5060'. [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: Sending to 86.183.229.226:5060 (NAT) [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: Splitting '190.220.68.151:14000' into... [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: ...host '190.220.68.151' and port ''. [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: <--- Transmitting (NAT) to 86.183.229.226:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 86.183.229.226:5060;branch=z9hG4bK49492ca915d4a6d7;received=86.183.229.226;rport=5060 From: "2005" ;tag=b2692681f68ef594 To: ;tag=as6beae17f Call-ID: 9836c9e3a3f1f4f4@192.168.1.64 CSeq: 12987 REGISTER Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="153ff686" Content-Length: 0 <------------> [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 86.183.229.226:5060 [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: Scheduling destruction of SIP dialog '9836c9e3a3f1f4f4@192.168.1.64' in 32000 ms (Method: REGISTER) [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:86.183.229.226:5060 ---> REGISTER sip:190.220.68.151:14000 SIP/2.0 Via: SIP/2.0/UDP 86.183.229.226:5060;branch=z9hG4bKfad730e47fdaffc6 From: "2005" ;tag=b2692681f68ef594 To: Contact: Supported: path Authorization: Digest username="2005", realm="asterisk", algorithm=MD5, uri="sip:190.220.68.151:14000", nonce="153ff686", response="4e1a07ba78babb34f277fd6c134b76fd" Call-ID: 9836c9e3a3f1f4f4@192.168.1.64 CSeq: 12988 REGISTER Expires: 600 User-Agent: Grandstream BT200 1.1.6.16 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Content-Length: 0 <-------------> [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 0 [ 41]: REGISTER sip:190.220.68.151:14000 SIP/2.0 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 1 [ 67]: Via: SIP/2.0/UDP 86.183.229.226:5060;branch=z9hG4bKfad730e47fdaffc6 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 2 [ 65]: From: "2005" ;tag=b2692681f68ef594 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 3 [ 35]: To: [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 4 [ 53]: Contact: [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 5 [ 15]: Supported: path [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 6 [165]: Authorization: Digest username="2005", realm="asterisk", algorithm=MD5, uri="sip:190.220.68.151:14000", nonce="153ff686", response="4e1a07ba78babb34f277fd6c134b76fd" [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 7 [ 38]: Call-ID: 9836c9e3a3f1f4f4@192.168.1.64 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 8 [ 20]: CSeq: 12988 REGISTER [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 9 [ 12]: Expires: 600 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 10 [ 38]: User-Agent: Grandstream BT200 1.1.6.16 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 11 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 12 [ 77]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: --- (14 headers 0 lines) --- [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: = Looking for Call ID: 9836c9e3a3f1f4f4@192.168.1.64 (Checking From) --From tag b2692681f68ef594 --To-tag [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: Splitting '190.220.68.151:14000' into... [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: ...host '190.220.68.151' and port '14000'. [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: Splitting '190.220.68.151:14000' into... [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: ...host '190.220.68.151' and port '14000'. [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Initializing initreq for method REGISTER - callid 9836c9e3a3f1f4f4@192.168.1.64 [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: Splitting '86.183.229.226:5060' into... [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: ...host '86.183.229.226' and port '5060'. [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: Sending to 86.183.229.226:5060 (NAT) [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: Splitting '190.220.68.151:14000' into... [2013-10-18 10:38:05] DEBUG[3380] netsock2.c: ...host '190.220.68.151' and port ''. [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Store REGISTER's src-IP:port for call routing. [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 0bc67de900a68c045f82f44e62acb370@192.168.3.50:14000 - OPTIONS (No RTP) [2013-10-18 10:38:05] DEBUG[3380] acl.c: For destination '86.183.229.226', our source address is '192.168.3.50'. [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Target address 86.183.229.226:5060 is not local, substituting externaddr [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 190.220.68.151:14000 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: SIP call-id changed from '0bc67de900a68c045f82f44e62acb370@192.168.3.50:14000' to '2107b7996ffb7b5749a45f1b2400daf9@190.220.68.151:14000' [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Initializing initreq for method OPTIONS - callid 2107b7996ffb7b5749a45f1b2400daf9@190.220.68.151:14000 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 0 [ 58]: OPTIONS sip:2005@86.183.229.226:5060;transport=udp SIP/2.0 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK262398d8;rport [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 3 [ 67]: From: "asterisk" ;tag=as62c80557 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 4 [ 48]: To: [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 5 [ 44]: Contact: [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 6 [ 62]: Call-ID: 2107b7996ffb7b5749a45f1b2400daf9@190.220.68.151:14000 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 9 [ 35]: Date: Fri, 18 Oct 2013 13:38:05 GMT [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: Reliably Transmitting (NAT) to 86.183.229.226:5060: OPTIONS sip:2005@86.183.229.226:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK262398d8;rport Max-Forwards: 70 From: "asterisk" ;tag=as62c80557 To: Contact: Call-ID: 2107b7996ffb7b5749a45f1b2400daf9@190.220.68.151:14000 CSeq: 102 OPTIONS User-Agent: PBX Date: Fri, 18 Oct 2013 13:38:05 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #84866 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 86.183.229.226:5060 [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: <--- Transmitting (NAT) to 86.183.229.226:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 86.183.229.226:5060;branch=z9hG4bKfad730e47fdaffc6;received=86.183.229.226;rport=5060 From: "2005" ;tag=b2692681f68ef594 To: ;tag=as6beae17f Call-ID: 9836c9e3a3f1f4f4@192.168.1.64 CSeq: 12988 REGISTER Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Expires: 600 Contact: ;expires=600 Date: Fri, 18 Oct 2013 13:38:05 GMT Content-Length: 0 <------------> [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 86.183.229.226:5060 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 7bfbe6b23652b81b50e296fa7f48e088@192.168.3.50:14000 - NOTIFY (No RTP) [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2013-10-18 10:38:05] DEBUG[3380] acl.c: For destination '86.183.229.226', our source address is '192.168.3.50'. [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Target address 86.183.229.226:5060 is not local, substituting externaddr [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 190.220.68.151:14000 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: SIP call-id changed from '7bfbe6b23652b81b50e296fa7f48e088@192.168.3.50:14000' to '7d934e217adc7870664a460b623e9825@190.220.68.151:14000' [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: Scheduling destruction of SIP dialog '7d934e217adc7870664a460b623e9825@190.220.68.151:14000' in 19584 ms (Method: NOTIFY) [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Initializing initreq for method NOTIFY - callid 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 0 [ 57]: NOTIFY sip:2005@86.183.229.226:5060;transport=udp SIP/2.0 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK5726a734;rport [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 3 [ 67]: From: "asterisk" ;tag=as7dd881a6 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 4 [ 48]: To: [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 5 [ 44]: Contact: [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 6 [ 62]: Call-ID: 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 7 [ 16]: CSeq: 102 NOTIFY [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 9 [ 22]: Event: message-summary [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Header 10 [ 48]: Content-Type: application/simple-message-summary [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: Reliably Transmitting (NAT) to 86.183.229.226:5060: NOTIFY sip:2005@86.183.229.226:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK5726a734;rport Max-Forwards: 70 From: "asterisk" ;tag=as7dd881a6 To: Contact: Call-ID: 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 CSeq: 102 NOTIFY User-Agent: PBX Event: message-summary Content-Type: application/simple-message-summary Content-Length: 97 Messages-Waiting: no Message-Account: sip:*5555@190.220.68.151:14000 Voice-Message: 0/0 (0/0) --- [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #84869 [2013-10-18 10:38:05] DEBUG[3380] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 86.183.229.226:5060 [2013-10-18 10:38:05] VERBOSE[3380] chan_sip.c: Scheduling destruction of SIP dialog '9836c9e3a3f1f4f4@192.168.1.64' in 32000 ms (Method: REGISTER) [2013-10-18 10:38:05] DEBUG[3344] devicestate.c: No provider found, checking channel drivers for SIP - 2005 [2013-10-18 10:38:05] DEBUG[3344] chan_sip.c: Checking device state for peer 2005 [2013-10-18 10:38:05] DEBUG[3344] devicestate.c: Changing state for SIP/2005 - state 1 (Not in use) [2013-10-18 10:38:05] DEBUG[3344] devicestate.c: device 'SIP/2005' state '1' [2013-10-18 10:38:05] DEBUG[3395] app_queue.c: Device 'SIP/2005' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: SIP TIMER: Rescheduling retransmission #84869 (1) NOTIFY - 4 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 612 ms (t1 306 ms (Retrans id #84869)) [2013-10-18 10:38:06] VERBOSE[3380] chan_sip.c: Retransmitting #1 (NAT) to 86.183.229.226:5060: NOTIFY sip:2005@86.183.229.226:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK5726a734;rport Max-Forwards: 70 From: "asterisk" ;tag=as7dd881a6 To: Contact: Call-ID: 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 CSeq: 102 NOTIFY User-Agent: PBX Event: message-summary Content-Type: application/simple-message-summary Content-Length: 97 Messages-Waiting: no Message-Account: sip:*5555@190.220.68.151:14000 Voice-Message: 0/0 (0/0) --- [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 86.183.229.226:5060 [2013-10-18 10:38:06] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:86.183.229.226:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK262398d8;rport From: "asterisk" ;tag=as62c80557 To: ;tag=39b1173aecd7e459 Call-ID: 2107b7996ffb7b5749a45f1b2400daf9@190.220.68.151:14000 CSeq: 102 OPTIONS User-Agent: Grandstream BT200 1.1.6.16 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 <-------------> [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK262398d8;rport [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 2 [ 67]: From: "asterisk" ;tag=as62c80557 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 3 [ 69]: To: ;tag=39b1173aecd7e459 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 4 [ 62]: Call-ID: 2107b7996ffb7b5749a45f1b2400daf9@190.220.68.151:14000 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 6 [ 38]: User-Agent: Grandstream BT200 1.1.6.16 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 7 [ 53]: Contact: [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 8 [ 77]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 9 [ 26]: Supported: replaces, timer [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2013-10-18 10:38:06] VERBOSE[3380] chan_sip.c: --- (11 headers 0 lines) --- [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: = Looking for Call ID: 2107b7996ffb7b5749a45f1b2400daf9@190.220.68.151:14000 (Checking To) --From tag as62c80557 --To-tag 39b1173aecd7e459 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #84866 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Stopping retransmission on '2107b7996ffb7b5749a45f1b2400daf9@190.220.68.151:14000' of Request 102: Match Found [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Destroying SIP dialog 2107b7996ffb7b5749a45f1b2400daf9@190.220.68.151:14000 [2013-10-18 10:38:06] VERBOSE[3380] chan_sip.c: Really destroying SIP dialog '2107b7996ffb7b5749a45f1b2400daf9@190.220.68.151:14000' Method: OPTIONS [2013-10-18 10:38:06] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:86.183.229.226:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK5726a734;rport From: "asterisk" ;tag=as7dd881a6 To: ;tag=73965cb65f536050 Call-ID: 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 CSeq: 102 NOTIFY User-Agent: Grandstream BT200 1.1.6.16 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 <-------------> [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK5726a734;rport [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 2 [ 67]: From: "asterisk" ;tag=as7dd881a6 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 3 [ 69]: To: ;tag=73965cb65f536050 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 4 [ 62]: Call-ID: 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 5 [ 16]: CSeq: 102 NOTIFY [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 6 [ 38]: User-Agent: Grandstream BT200 1.1.6.16 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 7 [ 53]: Contact: [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 8 [ 77]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 9 [ 26]: Supported: replaces, timer [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2013-10-18 10:38:06] VERBOSE[3380] chan_sip.c: --- (11 headers 0 lines) --- [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: = Looking for Call ID: 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 (Checking To) --From tag as7dd881a6 --To-tag 73965cb65f536050 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #84869 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Stopping retransmission on '7d934e217adc7870664a460b623e9825@190.220.68.151:14000' of Request 102: Match Found [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Got 200 accepted on NOTIFY 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Destroying SIP dialog 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 [2013-10-18 10:38:06] VERBOSE[3380] chan_sip.c: Really destroying SIP dialog '7d934e217adc7870664a460b623e9825@190.220.68.151:14000' Method: NOTIFY [2013-10-18 10:38:06] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:86.183.229.226:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK5726a734;rport From: "asterisk" ;tag=as7dd881a6 To: ;tag=147611765a799a79 Call-ID: 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 CSeq: 102 NOTIFY User-Agent: Grandstream BT200 1.1.6.16 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 <-------------> [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK5726a734;rport [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 2 [ 67]: From: "asterisk" ;tag=as7dd881a6 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 3 [ 69]: To: ;tag=147611765a799a79 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 4 [ 62]: Call-ID: 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 5 [ 16]: CSeq: 102 NOTIFY [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 6 [ 38]: User-Agent: Grandstream BT200 1.1.6.16 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 7 [ 53]: Contact: [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 8 [ 77]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 9 [ 26]: Supported: replaces, timer [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2013-10-18 10:38:06] VERBOSE[3380] chan_sip.c: --- (11 headers 0 lines) --- [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: = Looking for Call ID: 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 (Checking To) --From tag as7dd881a6 --To-tag 147611765a799a79 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: That's odd... Got a response on a call we don't know about. Callid 7d934e217adc7870664a460b623e9825@190.220.68.151:14000 [2013-10-18 10:38:06] DEBUG[3380] chan_sip.c: Invalid SIP message - rejected , no callid, len 516 [2013-10-18 10:38:09] DEBUG[3352] res_jabber.c: XML parsing successful [2013-10-18 10:38:09] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:192.168.1.216:50234 ---> REGISTER sip:192.168.3.50:14000 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.216:50234;branch=z9hG4bK-d8754z-8932662dfd0baf46-1---d8754z-;rport Max-Forwards: 70 Contact: To: "2036" From: "2036";tag=34068970 Call-ID: NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. CSeq: 6861 REGISTER Expires: 120 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE Supported: replaces User-Agent: 3CXPhone 6.0.26523.0 Authorization: Digest username="2036",realm="asterisk",nonce="566b13f3",uri="sip:192.168.3.50:14000",response="5085369ceafb4ef3edb5735e1b8db583",algorithm=MD5 Content-Length: 0 <-------------> [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 0 [ 39]: REGISTER sip:192.168.3.50:14000 SIP/2.0 [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 1 [ 93]: Via: SIP/2.0/UDP 192.168.1.216:50234;branch=z9hG4bK-d8754z-8932662dfd0baf46-1---d8754z-;rport [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 3 [ 66]: Contact: [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 4 [ 39]: To: "2036" [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 5 [ 54]: From: "2036";tag=34068970 [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 6 [ 53]: Call-ID: NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 7 [ 19]: CSeq: 6861 REGISTER [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 8 [ 12]: Expires: 120 [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 9 [ 91]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 10 [ 19]: Supported: replaces [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 11 [ 32]: User-Agent: 3CXPhone 6.0.26523.0 [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 12 [158]: Authorization: Digest username="2036",realm="asterisk",nonce="566b13f3",uri="sip:192.168.3.50:14000",response="5085369ceafb4ef3edb5735e1b8db583",algorithm=MD5 [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [2013-10-18 10:38:09] VERBOSE[3380] chan_sip.c: --- (14 headers 0 lines) --- [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: = Looking for Call ID: NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. (Checking From) --From tag 34068970 --To-tag [2013-10-18 10:38:09] DEBUG[3380] acl.c: For destination '192.168.1.216', our source address is '192.168.3.50'. [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Target address 192.168.1.216:50234 is not local, substituting externaddr [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 190.220.68.151:14000 [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. - REGISTER (No RTP) [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Initializing initreq for method REGISTER - callid NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. [2013-10-18 10:38:09] DEBUG[3380] netsock2.c: Splitting '192.168.1.216:50234' into... [2013-10-18 10:38:09] DEBUG[3380] netsock2.c: ...host '192.168.1.216' and port '50234'. [2013-10-18 10:38:09] VERBOSE[3380] chan_sip.c: Sending to 192.168.1.216:50234 (NAT) [2013-10-18 10:38:09] DEBUG[3380] netsock2.c: Splitting '192.168.3.50:14000' into... [2013-10-18 10:38:09] DEBUG[3380] netsock2.c: ...host '192.168.3.50' and port ''. [2013-10-18 10:38:09] VERBOSE[3380] chan_sip.c: <--- Transmitting (NAT) to 192.168.1.216:50234 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.216:50234;branch=z9hG4bK-d8754z-8932662dfd0baf46-1---d8754z-;received=192.168.1.216;rport=50234 From: "2036";tag=34068970 To: "2036";tag=as214b0246 Call-ID: NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. CSeq: 6861 REGISTER Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="3ad1b9d6" Content-Length: 0 <------------> [2013-10-18 10:38:09] DEBUG[3380] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.1.216:50234 [2013-10-18 10:38:09] VERBOSE[3380] chan_sip.c: Scheduling destruction of SIP dialog 'NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY.' in 32000 ms (Method: REGISTER) [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:192.168.1.216:50234 ---> REGISTER sip:192.168.3.50:14000 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.216:50234;branch=z9hG4bK-d8754z-80308631aa720035-1---d8754z-;rport Max-Forwards: 70 Contact: To: "2036" From: "2036";tag=34068970 Call-ID: NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. CSeq: 6862 REGISTER Expires: 120 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE Supported: replaces User-Agent: 3CXPhone 6.0.26523.0 Authorization: Digest username="2036",realm="asterisk",nonce="3ad1b9d6",uri="sip:192.168.3.50:14000",response="62d1948896eadc8ccd8acb81fbed5bfe",algorithm=MD5 Content-Length: 0 <-------------> [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 0 [ 39]: REGISTER sip:192.168.3.50:14000 SIP/2.0 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 1 [ 93]: Via: SIP/2.0/UDP 192.168.1.216:50234;branch=z9hG4bK-d8754z-80308631aa720035-1---d8754z-;rport [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 3 [ 66]: Contact: [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 4 [ 39]: To: "2036" [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 5 [ 54]: From: "2036";tag=34068970 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 6 [ 53]: Call-ID: NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 7 [ 19]: CSeq: 6862 REGISTER [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 8 [ 12]: Expires: 120 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 9 [ 91]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 10 [ 19]: Supported: replaces [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 11 [ 32]: User-Agent: 3CXPhone 6.0.26523.0 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 12 [158]: Authorization: Digest username="2036",realm="asterisk",nonce="3ad1b9d6",uri="sip:192.168.3.50:14000",response="62d1948896eadc8ccd8acb81fbed5bfe",algorithm=MD5 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: --- (14 headers 0 lines) --- [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: = Looking for Call ID: NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. (Checking From) --From tag 34068970 --To-tag [2013-10-18 10:38:10] DEBUG[3380] netsock2.c: Splitting '192.168.3.50:14000' into... [2013-10-18 10:38:10] DEBUG[3380] netsock2.c: ...host '192.168.3.50' and port '14000'. [2013-10-18 10:38:10] DEBUG[3380] netsock2.c: Splitting '192.168.3.50:14000' into... [2013-10-18 10:38:10] DEBUG[3380] netsock2.c: ...host '192.168.3.50' and port '14000'. [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Initializing initreq for method REGISTER - callid NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. [2013-10-18 10:38:10] DEBUG[3380] netsock2.c: Splitting '192.168.1.216:50234' into... [2013-10-18 10:38:10] DEBUG[3380] netsock2.c: ...host '192.168.1.216' and port '50234'. [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: Sending to 192.168.1.216:50234 (NAT) [2013-10-18 10:38:10] DEBUG[3380] netsock2.c: Splitting '192.168.3.50:14000' into... [2013-10-18 10:38:10] DEBUG[3380] netsock2.c: ...host '192.168.3.50' and port ''. [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Store REGISTER's src-IP:port for call routing. [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 271092d66b95a8a9577147874c04fe91@192.168.3.50:14000 - OPTIONS (No RTP) [2013-10-18 10:38:10] DEBUG[3380] acl.c: For destination '192.168.1.216', our source address is '192.168.3.50'. [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Target address 192.168.1.216:50234 is not local, substituting externaddr [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 190.220.68.151:14000 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: SIP call-id changed from '271092d66b95a8a9577147874c04fe91@192.168.3.50:14000' to '0bd60daa110c7ce61ebab844636b569b@190.220.68.151:14000' [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Initializing initreq for method OPTIONS - callid 0bd60daa110c7ce61ebab844636b569b@190.220.68.151:14000 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 0 [ 71]: OPTIONS sip:2036@192.168.1.216:50234;rinstance=570f2cc8ab5dd150 SIP/2.0 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK5c0f20c4;rport [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 3 [ 67]: From: "asterisk" ;tag=as46c320f3 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 4 [ 61]: To: [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 5 [ 44]: Contact: [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 6 [ 62]: Call-ID: 0bd60daa110c7ce61ebab844636b569b@190.220.68.151:14000 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 9 [ 35]: Date: Fri, 18 Oct 2013 13:38:10 GMT [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: Reliably Transmitting (NAT) to 192.168.1.216:50234: OPTIONS sip:2036@192.168.1.216:50234;rinstance=570f2cc8ab5dd150 SIP/2.0 Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK5c0f20c4;rport Max-Forwards: 70 From: "asterisk" ;tag=as46c320f3 To: Contact: Call-ID: 0bd60daa110c7ce61ebab844636b569b@190.220.68.151:14000 CSeq: 102 OPTIONS User-Agent: PBX Date: Fri, 18 Oct 2013 13:38:10 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #84874 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.1.216:50234 [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: <--- Transmitting (NAT) to 192.168.1.216:50234 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.216:50234;branch=z9hG4bK-d8754z-80308631aa720035-1---d8754z-;received=192.168.1.216;rport=50234 From: "2036";tag=34068970 To: "2036";tag=as214b0246 Call-ID: NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. CSeq: 6862 REGISTER Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Expires: 120 Contact: ;expires=120 Date: Fri, 18 Oct 2013 13:38:10 GMT Content-Length: 0 <------------> [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.1.216:50234 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 28d58ff712e756bf1aaa7eb8445b0ac1@192.168.3.50:14000 - NOTIFY (No RTP) [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2013-10-18 10:38:10] DEBUG[3380] acl.c: For destination '192.168.1.216', our source address is '192.168.3.50'. [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Target address 192.168.1.216:50234 is not local, substituting externaddr [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 190.220.68.151:14000 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: SIP call-id changed from '28d58ff712e756bf1aaa7eb8445b0ac1@192.168.3.50:14000' to '5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000' [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: Scheduling destruction of SIP dialog '5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000' in 11840 ms (Method: NOTIFY) [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Initializing initreq for method NOTIFY - callid 5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 0 [ 70]: NOTIFY sip:2036@192.168.1.216:50234;rinstance=570f2cc8ab5dd150 SIP/2.0 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK483da904;rport [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 3 [ 67]: From: "asterisk" ;tag=as32ffd7de [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 4 [ 61]: To: [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 5 [ 44]: Contact: [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 6 [ 62]: Call-ID: 5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 7 [ 16]: CSeq: 102 NOTIFY [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 9 [ 22]: Event: message-summary [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 10 [ 48]: Content-Type: application/simple-message-summary [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: Reliably Transmitting (NAT) to 192.168.1.216:50234: NOTIFY sip:2036@192.168.1.216:50234;rinstance=570f2cc8ab5dd150 SIP/2.0 Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK483da904;rport Max-Forwards: 70 From: "asterisk" ;tag=as32ffd7de To: Contact: Call-ID: 5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000 CSeq: 102 NOTIFY User-Agent: PBX Event: message-summary Content-Type: application/simple-message-summary Content-Length: 97 Messages-Waiting: no Message-Account: sip:*5555@190.220.68.151:14000 Voice-Message: 0/0 (0/0) --- [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #84877 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 192.168.1.216:50234 [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: Scheduling destruction of SIP dialog 'NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY.' in 32000 ms (Method: REGISTER) [2013-10-18 10:38:10] DEBUG[3344] devicestate.c: No provider found, checking channel drivers for SIP - 2036 [2013-10-18 10:38:10] DEBUG[3344] chan_sip.c: Checking device state for peer 2036 [2013-10-18 10:38:10] DEBUG[3344] devicestate.c: Changing state for SIP/2036 - state 1 (Not in use) [2013-10-18 10:38:10] DEBUG[3344] devicestate.c: device 'SIP/2036' state '1' [2013-10-18 10:38:10] DEBUG[3395] app_queue.c: Device 'SIP/2036' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:192.168.1.216:50234 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK5c0f20c4;rport=14000;received=192.168.3.50 Contact: To: ;tag=9a06c326 From: "asterisk";tag=as46c320f3 Call-ID: 0bd60daa110c7ce61ebab844636b569b@190.220.68.151:14000 CSeq: 102 OPTIONS Accept: application/sdp Accept-Language: en Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE Supported: replaces Allow-Events: presence, message-summary, tunnel-info Content-Length: 0 <-------------> [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 1 [ 94]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK5c0f20c4;rport=14000;received=192.168.3.50 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 2 [ 34]: Contact: [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 3 [ 74]: To: ;tag=9a06c326 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 4 [ 66]: From: "asterisk";tag=as46c320f3 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 5 [ 62]: Call-ID: 0bd60daa110c7ce61ebab844636b569b@190.220.68.151:14000 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 6 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 7 [ 23]: Accept: application/sdp [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 8 [ 19]: Accept-Language: en [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 9 [ 91]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 10 [ 19]: Supported: replaces [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 11 [ 52]: Allow-Events: presence, message-summary, tunnel-info [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: --- (13 headers 0 lines) --- [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: = Looking for Call ID: 0bd60daa110c7ce61ebab844636b569b@190.220.68.151:14000 (Checking To) --From tag as46c320f3 --To-tag 9a06c326 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #84874 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Stopping retransmission on '0bd60daa110c7ce61ebab844636b569b@190.220.68.151:14000' of Request 102: Match Found [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Destroying SIP dialog 0bd60daa110c7ce61ebab844636b569b@190.220.68.151:14000 [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: Really destroying SIP dialog '0bd60daa110c7ce61ebab844636b569b@190.220.68.151:14000' Method: OPTIONS [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:192.168.1.216:50234 ---> SIP/2.0 405 Method Not Allowed Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK483da904;rport=14000;received=192.168.3.50 To: ;tag=555e337e From: "asterisk";tag=as32ffd7de Call-ID: 5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000 CSeq: 102 NOTIFY Content-Length: 0 <-------------> [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 0 [ 30]: SIP/2.0 405 Method Not Allowed [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 1 [ 94]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK483da904;rport=14000;received=192.168.3.50 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 2 [ 74]: To: ;tag=555e337e [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 3 [ 66]: From: "asterisk";tag=as32ffd7de [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 4 [ 62]: Call-ID: 5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 5 [ 16]: CSeq: 102 NOTIFY [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: --- (7 headers 0 lines) --- [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: = Looking for Call ID: 5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000 (Checking To) --From tag as32ffd7de --To-tag 555e337e [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #84877 [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Stopping retransmission on '5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000' of Request 102: Match Found [2013-10-18 10:38:10] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:192.168.1.216:50234 ---> <-------------> [2013-10-18 10:38:10] DEBUG[3380] chan_sip.c: Header 0 [ 0]: [2013-10-18 10:38:10] VERBOSE[9655] chan_sip.c: <--- SIP read from TCP:181.167.11.205:55169 ---> INVITE sip:9000@190.220.68.151:14000 SIP/2.0 Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjKNh1ve4KjdNhLjkmnUL6Qx9ungaZdIMh;alias Max-Forwards: 70 From: "2035" ;tag=tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo To: sip:9000@190.220.68.151 Contact: Call-ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K CSeq: 27492 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub User-Agent: Bria Android 2.3.6 Content-Type: application/sdp Content-Length: 473 v=0 o=- 3591092290 3591092290 IN IP4 192.168.2.101 s=cpc_med c=IN IP4 192.168.2.101 t=0 0 m=audio 4000 RTP/SAVP 18 0 8 9 101 a=sendrecv a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:fWxoTC0jY3RbDLmaHi8zxUnJcmb2yuG9SRIj9lTS a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:H9LCQvxEMOaq06v4HTfNQdF/z2LK6DsP0uvTSBg/ <-------------> [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 0 [ 44]: INVITE sip:9000@190.220.68.151:14000 SIP/2.0 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 1 [ 98]: Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjKNh1ve4KjdNhLjkmnUL6Qx9ungaZdIMh;alias [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 3 [ 75]: From: "2035" ;tag=tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 4 [ 27]: To: sip:9000@190.220.68.151 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 5 [ 57]: Contact: [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 6 [ 41]: Call-ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 7 [ 18]: CSeq: 27492 INVITE [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 8 [ 96]: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 9 [ 46]: Supported: replaces, 100rel, timer, norefersub [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 10 [ 30]: User-Agent: Bria Android 2.3.6 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 11 [ 29]: Content-Type: application/sdp [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 12 [ 19]: Content-Length: 473 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 13 [ 0]: [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 0 [ 3]: v=0 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 1 [ 46]: o=- 3591092290 3591092290 IN IP4 192.168.2.101 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 2 [ 9]: s=cpc_med [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 3 [ 22]: c=IN IP4 192.168.2.101 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 4 [ 5]: t=0 0 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 5 [ 34]: m=audio 4000 RTP/SAVP 18 0 8 9 101 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 6 [ 10]: a=sendrecv [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 7 [ 21]: a=rtpmap:18 G729/8000 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 8 [ 19]: a=fmtp:18 annexb=no [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 9 [ 20]: a=rtpmap:0 PCMU/8000 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 11 [ 20]: a=rtpmap:9 G722/8000 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 13 [ 15]: a=fmtp:101 0-15 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 14 [ 82]: a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:fWxoTC0jY3RbDLmaHi8zxUnJcmb2yuG9SRIj9lTS [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Body 15 [ 82]: a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:H9LCQvxEMOaq06v4HTfNQdF/z2LK6DsP0uvTSBg/ [2013-10-18 10:38:10] VERBOSE[9655] chan_sip.c: --- (13 headers 16 lines) --- [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: = Looking for Call ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K (Checking From) --From tag tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo --To-tag [2013-10-18 10:38:10] DEBUG[9655] acl.c: For destination '181.167.11.205', our source address is '192.168.3.50'. [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Target address 181.167.11.205:55169 is not local, substituting externaddr [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Setting SIP_TRANSPORT_TCP with address 190.220.68.151:5060 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Allocating new SIP dialog for oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K - INVITE (No RTP) [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [2013-10-18 10:38:10] DEBUG[9655] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces, 100rel, timer, norefersub" [2013-10-18 10:38:10] DEBUG[9655] sip/reqresp_parser.c: Found SIP option: -replaces- [2013-10-18 10:38:10] DEBUG[9655] sip/reqresp_parser.c: Matched SIP option: replaces [2013-10-18 10:38:10] DEBUG[9655] sip/reqresp_parser.c: Found SIP option: -100rel- [2013-10-18 10:38:10] DEBUG[9655] sip/reqresp_parser.c: Matched SIP option: 100rel [2013-10-18 10:38:10] DEBUG[9655] sip/reqresp_parser.c: Found SIP option: -timer- [2013-10-18 10:38:10] DEBUG[9655] sip/reqresp_parser.c: Matched SIP option: timer [2013-10-18 10:38:10] DEBUG[9655] sip/reqresp_parser.c: Found SIP option: -norefersub- [2013-10-18 10:38:10] DEBUG[9655] sip/reqresp_parser.c: Matched SIP option: norefersub [2013-10-18 10:38:10] DEBUG[9655] netsock2.c: Splitting '181.167.11.205:55169' into... [2013-10-18 10:38:10] DEBUG[9655] netsock2.c: ...host '181.167.11.205' and port '55169'. [2013-10-18 10:38:10] VERBOSE[9655] chan_sip.c: Sending to 181.167.11.205:55169 (NAT) [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Initializing initreq for method INVITE - callid oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K [2013-10-18 10:38:10] VERBOSE[9655] chan_sip.c: Using INVITE request as basis request - oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K [2013-10-18 10:38:10] DEBUG[9655] netsock2.c: Splitting '190.220.68.151' into... [2013-10-18 10:38:10] DEBUG[9655] netsock2.c: ...host '190.220.68.151' and port ''. [2013-10-18 10:38:10] VERBOSE[9655] chan_sip.c: Found peer '2035' for '2035' from 181.167.11.205:55169 [2013-10-18 10:38:10] VERBOSE[9655] chan_sip.c: <--- Reliably Transmitting (NAT) to 181.167.11.205:55169 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 181.167.11.205:55169;branch=z9hG4bKPjKNh1ve4KjdNhLjkmnUL6Qx9ungaZdIMh;alias;received=181.167.11.205;rport=55169 From: "2035" ;tag=tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo To: sip:9000@190.220.68.151;tag=as0ad6a462 Call-ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K CSeq: 27492 INVITE Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="447994e4" Content-Length: 0 <------------> [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Trying to put 'SIP/2.0 401' onto TCP socket destined for 181.167.11.205:55169 [2013-10-18 10:38:10] VERBOSE[9655] chan_sip.c: Scheduling destruction of SIP dialog 'oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K' in 23232 ms (Method: INVITE) [2013-10-18 10:38:10] VERBOSE[9655] chan_sip.c: <--- SIP read from TCP:181.167.11.205:55169 ---> ACK sip:9000@190.220.68.151:14000 SIP/2.0 Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjKNh1ve4KjdNhLjkmnUL6Qx9ungaZdIMh;alias Max-Forwards: 70 From: "2035" ;tag=tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo To: sip:9000@190.220.68.151;tag=as0ad6a462 Call-ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K CSeq: 27492 ACK Content-Length: 0 <-------------> [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 0 [ 41]: ACK sip:9000@190.220.68.151:14000 SIP/2.0 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 1 [ 98]: Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjKNh1ve4KjdNhLjkmnUL6Qx9ungaZdIMh;alias [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 3 [ 75]: From: "2035" ;tag=tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 4 [ 42]: To: sip:9000@190.220.68.151;tag=as0ad6a462 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 5 [ 41]: Call-ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 6 [ 15]: CSeq: 27492 ACK [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2013-10-18 10:38:10] VERBOSE[9655] chan_sip.c: --- (8 headers 0 lines) --- [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: = Looking for Call ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K (Checking From) --From tag tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo --To-tag as0ad6a462 [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [2013-10-18 10:38:10] DEBUG[9655] chan_sip.c: Stopping retransmission on 'oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K' of Response 27492: Match Not Found [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: <--- SIP read from TCP:181.167.11.205:55169 ---> INVITE sip:9000@190.220.68.151:14000 SIP/2.0 Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPj1nM8yaMUiN.L9ztWf3JkUEC7kWU0zDnA;alias Max-Forwards: 70 From: "2035" ;tag=tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo To: sip:9000@190.220.68.151 Contact: Call-ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K CSeq: 27493 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub User-Agent: Bria Android 2.3.6 Authorization: Digest username="2035", realm="asterisk", nonce="447994e4", uri="sip:9000@190.220.68.151:14000", response="d59c23e2368c923267a0ada3056f4545", algorithm=MD5 Content-Type: application/sdp Content-Length: 473 v=0 o=- 3591092290 3591092290 IN IP4 192.168.2.101 s=cpc_med c=IN IP4 192.168.2.101 t=0 0 m=audio 4000 RTP/SAVP 18 0 8 9 101 a=sendrecv a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:fWxoTC0jY3RbDLmaHi8zxUnJcmb2yuG9SRIj9lTS a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:H9LCQvxEMOaq06v4HTfNQdF/z2LK6DsP0uvTSBg/ <-------------> [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 0 [ 44]: INVITE sip:9000@190.220.68.151:14000 SIP/2.0 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 1 [ 98]: Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPj1nM8yaMUiN.L9ztWf3JkUEC7kWU0zDnA;alias [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 3 [ 75]: From: "2035" ;tag=tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 4 [ 27]: To: sip:9000@190.220.68.151 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 5 [ 57]: Contact: [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 6 [ 41]: Call-ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 7 [ 18]: CSeq: 27493 INVITE [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 8 [ 96]: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 9 [ 46]: Supported: replaces, 100rel, timer, norefersub [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 10 [ 30]: User-Agent: Bria Android 2.3.6 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 11 [170]: Authorization: Digest username="2035", realm="asterisk", nonce="447994e4", uri="sip:9000@190.220.68.151:14000", response="d59c23e2368c923267a0ada3056f4545", algorithm=MD5 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 13 [ 19]: Content-Length: 473 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 14 [ 0]: [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 0 [ 3]: v=0 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 1 [ 46]: o=- 3591092290 3591092290 IN IP4 192.168.2.101 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 2 [ 9]: s=cpc_med [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 3 [ 22]: c=IN IP4 192.168.2.101 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 4 [ 5]: t=0 0 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 5 [ 34]: m=audio 4000 RTP/SAVP 18 0 8 9 101 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 6 [ 10]: a=sendrecv [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 7 [ 21]: a=rtpmap:18 G729/8000 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 8 [ 19]: a=fmtp:18 annexb=no [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 9 [ 20]: a=rtpmap:0 PCMU/8000 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 11 [ 20]: a=rtpmap:9 G722/8000 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 13 [ 15]: a=fmtp:101 0-15 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 14 [ 82]: a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:fWxoTC0jY3RbDLmaHi8zxUnJcmb2yuG9SRIj9lTS [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Body 15 [ 82]: a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:H9LCQvxEMOaq06v4HTfNQdF/z2LK6DsP0uvTSBg/ [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: --- (14 headers 16 lines) --- [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: = Looking for Call ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K (Checking From) --From tag tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo --To-tag [2013-10-18 10:38:11] DEBUG[9655] netsock2.c: Splitting '190.220.68.151:14000' into... [2013-10-18 10:38:11] DEBUG[9655] netsock2.c: ...host '190.220.68.151' and port '14000'. [2013-10-18 10:38:11] DEBUG[9655] netsock2.c: Splitting '190.220.68.151:14000' into... [2013-10-18 10:38:11] DEBUG[9655] netsock2.c: ...host '190.220.68.151' and port '14000'. [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [2013-10-18 10:38:11] DEBUG[9655] netsock2.c: Splitting '181.167.11.205:55169' into... [2013-10-18 10:38:11] DEBUG[9655] netsock2.c: ...host '181.167.11.205' and port '55169'. [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Sending to 181.167.11.205:55169 (NAT) [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Initializing initreq for method INVITE - callid oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Using INVITE request as basis request - oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K [2013-10-18 10:38:11] DEBUG[9655] netsock2.c: Splitting '190.220.68.151' into... [2013-10-18 10:38:11] DEBUG[9655] netsock2.c: ...host '190.220.68.151' and port ''. [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Found peer '2035' for '2035' from 181.167.11.205:55169 [2013-10-18 10:38:11] DEBUG[9655] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f30bc738f18' [2013-10-18 10:38:11] DEBUG[9655] res_rtp_asterisk.c: Allocated port 10032 for RTP instance '0x7f30bc738f18' [2013-10-18 10:38:11] DEBUG[9655] rtp_engine.c: RTP instance '0x7f30bc738f18' is setup and ready to go [2013-10-18 10:38:11] DEBUG[9655] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f30bc741028' [2013-10-18 10:38:11] DEBUG[9655] res_rtp_asterisk.c: Allocated port 10026 for RTP instance '0x7f30bc741028' [2013-10-18 10:38:11] DEBUG[9655] rtp_engine.c: RTP instance '0x7f30bc741028' is setup and ready to go [2013-10-18 10:38:11] DEBUG[9655] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f30bc741028' [2013-10-18 10:38:11] VERBOSE[9655] netsock2.c: == Using SIP VIDEO CoS mark 6 [2013-10-18 10:38:11] DEBUG[9655] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f30bc738f18' [2013-10-18 10:38:11] VERBOSE[9655] netsock2.c: == Using SIP RTP CoS mark 5 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Setting NAT on RTP to On [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Setting NAT on VRTP to On [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing session-level SDP o=- 3591092290 3591092290 IN IP4 192.168.2.101... OK. [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing session-level SDP s=cpc_med... UNSUPPORTED OR FAILED. [2013-10-18 10:38:11] DEBUG[9655] netsock2.c: Splitting '192.168.2.101' into... [2013-10-18 10:38:11] DEBUG[9655] netsock2.c: ...host '192.168.2.101' and port ''. [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.2.101... OK. [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Found RTP audio format 18 [2013-10-18 10:38:11] DEBUG[9655] rtp_engine.c: Setting payload 18 based on m type on 0x7f309de890a0 [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Found RTP audio format 0 [2013-10-18 10:38:11] DEBUG[9655] rtp_engine.c: Setting payload 0 based on m type on 0x7f309de890a0 [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Found RTP audio format 8 [2013-10-18 10:38:11] DEBUG[9655] rtp_engine.c: Setting payload 8 based on m type on 0x7f309de890a0 [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Found RTP audio format 9 [2013-10-18 10:38:11] DEBUG[9655] rtp_engine.c: Setting payload 9 based on m type on 0x7f309de890a0 [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Found RTP audio format 101 [2013-10-18 10:38:11] DEBUG[9655] rtp_engine.c: Setting payload 101 based on m type on 0x7f309de890a0 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Found audio description format G729 for ID 18 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED OR FAILED. [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Found audio description format PCMU for ID 0 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Found audio description format PCMA for ID 8 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Found audio description format G722 for ID 9 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Found audio description format telephone-event for ID 101 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [2013-10-18 10:38:11] DEBUG[9655] sip/sdp_crypto.c: local_key64 ro1ZxO7b1bZyMSBq3b7600oGxh8IICcMYPF5vwcm len 40 [2013-10-18 10:38:11] WARNING[9655] sip/sdp_crypto.c: Could not set SRTP policies [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:fWxoTC0jY3RbDLmaHi8zxUnJcmb2yuG9SRIj9lTS... UNSUPPORTED OR FAILED. [2013-10-18 10:38:11] WARNING[9655] sip/sdp_crypto.c: Could not set SRTP policies [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:H9LCQvxEMOaq06v4HTfNQdF/z2LK6DsP0uvTSBg/... UNSUPPORTED OR FAILED. [2013-10-18 10:38:11] WARNING[9655] chan_sip.c: Rejecting secure audio stream without encryption details: audio 4000 RTP/SAVP 18 0 8 9 101 [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: <--- Reliably Transmitting (NAT) to 181.167.11.205:55169 ---> SIP/2.0 488 Not acceptable here Via: SIP/2.0/TCP 181.167.11.205:55169;branch=z9hG4bKPj1nM8yaMUiN.L9ztWf3JkUEC7kWU0zDnA;alias;received=181.167.11.205;rport=55169 From: "2035" ;tag=tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo To: sip:9000@190.220.68.151;tag=as0ad6a462 Call-ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K CSeq: 27493 INVITE Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Trying to put 'SIP/2.0 488' onto TCP socket destined for 181.167.11.205:55169 [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: Scheduling destruction of SIP dialog 'oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K' in 23232 ms (Method: INVITE) [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: No compatible codecs for this SIP call. [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: SIP message could not be handled, bad request: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: <--- SIP read from TCP:181.167.11.205:55169 ---> ACK sip:9000@190.220.68.151:14000 SIP/2.0 Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPj1nM8yaMUiN.L9ztWf3JkUEC7kWU0zDnA;alias Max-Forwards: 70 From: "2035" ;tag=tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo To: sip:9000@190.220.68.151;tag=as0ad6a462 Call-ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K CSeq: 27493 ACK Content-Length: 0 <-------------> [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 0 [ 41]: ACK sip:9000@190.220.68.151:14000 SIP/2.0 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 1 [ 98]: Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPj1nM8yaMUiN.L9ztWf3JkUEC7kWU0zDnA;alias [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 3 [ 75]: From: "2035" ;tag=tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 4 [ 42]: To: sip:9000@190.220.68.151;tag=as0ad6a462 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 5 [ 41]: Call-ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 6 [ 15]: CSeq: 27493 ACK [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2013-10-18 10:38:11] VERBOSE[9655] chan_sip.c: --- (8 headers 0 lines) --- [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: = Looking for Call ID: oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K (Checking From) --From tag tmABQ7LeGxrU.xu3bfJr9UYC.V5PGVyo --To-tag as0ad6a462 [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [2013-10-18 10:38:11] DEBUG[9655] chan_sip.c: Stopping retransmission on 'oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K' of Response 27493: Match Not Found [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 6e165e28705d414726c42cc255fd76bf@192.168.3.50:14000 - OPTIONS (No RTP) [2013-10-18 10:38:18] DEBUG[3380] acl.c: For destination '186.23.144.43', our source address is '192.168.3.50'. [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Target address 186.23.144.43:14016 is not local, substituting externaddr [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 190.220.68.151:14000 [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: SIP call-id changed from '6e165e28705d414726c42cc255fd76bf@192.168.3.50:14000' to '4f8b8e1539f1ffda72ce1a76011f2ab8@190.220.68.151:14000' [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Initializing initreq for method OPTIONS - callid 4f8b8e1539f1ffda72ce1a76011f2ab8@190.220.68.151:14000 [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 0 [ 44]: OPTIONS sip:2003@192.168.3.180:14000 SIP/2.0 [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK23a69559;rport [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 3 [ 67]: From: "asterisk" ;tag=as0b243235 [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 4 [ 34]: To: [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 5 [ 44]: Contact: [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 6 [ 62]: Call-ID: 4f8b8e1539f1ffda72ce1a76011f2ab8@190.220.68.151:14000 [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 9 [ 35]: Date: Fri, 18 Oct 2013 13:38:18 GMT [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2013-10-18 10:38:18] VERBOSE[3380] chan_sip.c: Reliably Transmitting (NAT) to 186.23.144.43:14016: OPTIONS sip:2003@192.168.3.180:14000 SIP/2.0 Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK23a69559;rport Max-Forwards: 70 From: "asterisk" ;tag=as0b243235 To: Contact: Call-ID: 4f8b8e1539f1ffda72ce1a76011f2ab8@190.220.68.151:14000 CSeq: 102 OPTIONS User-Agent: PBX Date: Fri, 18 Oct 2013 13:38:18 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #84882 [2013-10-18 10:38:18] DEBUG[3380] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 186.23.144.43:14016 [2013-10-18 10:38:19] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:186.23.144.43:14016 ---> SIP/2.0 200 OK To: ;tag=108f76adac592b5i1 From: "asterisk" ;tag=as0b243235 Call-ID: 4f8b8e1539f1ffda72ce1a76011f2ab8@190.220.68.151:14000 CSeq: 102 OPTIONS Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK23a69559 Server: Linksys/PAP2-3.1.22(LS) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura, replaces <-------------> [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Header 1 [ 56]: To: ;tag=108f76adac592b5i1 [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Header 2 [ 67]: From: "asterisk" ;tag=as0b243235 [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Header 3 [ 62]: Call-ID: 4f8b8e1539f1ffda72ce1a76011f2ab8@190.220.68.151:14000 [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Header 4 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Header 5 [ 60]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK23a69559 [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Header 6 [ 31]: Server: Linksys/PAP2-3.1.22(LS) [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Header 8 [ 61]: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Header 9 [ 29]: Supported: x-sipura, replaces [2013-10-18 10:38:19] VERBOSE[3380] chan_sip.c: --- (10 headers 0 lines) --- [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: = Looking for Call ID: 4f8b8e1539f1ffda72ce1a76011f2ab8@190.220.68.151:14000 (Checking To) --From tag as0b243235 --To-tag 108f76adac592b5i1 [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #84882 [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Stopping retransmission on '4f8b8e1539f1ffda72ce1a76011f2ab8@190.220.68.151:14000' of Request 102: Match Found [2013-10-18 10:38:19] DEBUG[3380] chan_sip.c: Destroying SIP dialog 4f8b8e1539f1ffda72ce1a76011f2ab8@190.220.68.151:14000 [2013-10-18 10:38:19] VERBOSE[3380] chan_sip.c: Really destroying SIP dialog '4f8b8e1539f1ffda72ce1a76011f2ab8@190.220.68.151:14000' Method: OPTIONS [2013-10-18 10:38:21] DEBUG[3380] chan_sip.c: Auto destroying SIP dialog '5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000' [2013-10-18 10:38:21] DEBUG[3380] chan_sip.c: Destroying SIP dialog 5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000 [2013-10-18 10:38:21] VERBOSE[3380] chan_sip.c: Really destroying SIP dialog '5268f31a5b55c5ca409a4280133e85e1@190.220.68.151:14000' Method: NOTIFY [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: <--- SIP read from TCP:181.167.11.205:55169 ---> INVITE sip:2000@190.220.68.151:14000 SIP/2.0 Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjUde03fQ1sSJqVXjhgdWvr3JJ4.Rs8Jby;alias Max-Forwards: 70 From: "2035" ;tag=6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS To: sip:2000@190.220.68.151 Contact: Call-ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh CSeq: 27178 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub User-Agent: Bria Android 2.3.6 Content-Type: application/sdp Content-Length: 473 v=0 o=- 3591092302 3591092302 IN IP4 192.168.2.101 s=cpc_med c=IN IP4 192.168.2.101 t=0 0 m=audio 4002 RTP/SAVP 18 0 8 9 101 a=sendrecv a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:gluXdO/fvpC5mEy2qioJKQW6/6gPd4FggJo5iT3d a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:acEYpw764FyrKO4qQ1LNZUArWcZXyRhfcR5V7YGO <-------------> [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 0 [ 44]: INVITE sip:2000@190.220.68.151:14000 SIP/2.0 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 1 [ 98]: Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjUde03fQ1sSJqVXjhgdWvr3JJ4.Rs8Jby;alias [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 3 [ 75]: From: "2035" ;tag=6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 4 [ 27]: To: sip:2000@190.220.68.151 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 5 [ 57]: Contact: [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 6 [ 41]: Call-ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 7 [ 18]: CSeq: 27178 INVITE [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 8 [ 96]: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 9 [ 46]: Supported: replaces, 100rel, timer, norefersub [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 10 [ 30]: User-Agent: Bria Android 2.3.6 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 11 [ 29]: Content-Type: application/sdp [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 12 [ 19]: Content-Length: 473 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 13 [ 0]: [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 0 [ 3]: v=0 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 1 [ 46]: o=- 3591092302 3591092302 IN IP4 192.168.2.101 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 2 [ 9]: s=cpc_med [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 3 [ 22]: c=IN IP4 192.168.2.101 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 4 [ 5]: t=0 0 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 5 [ 34]: m=audio 4002 RTP/SAVP 18 0 8 9 101 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 6 [ 10]: a=sendrecv [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 7 [ 21]: a=rtpmap:18 G729/8000 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 8 [ 19]: a=fmtp:18 annexb=no [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 9 [ 20]: a=rtpmap:0 PCMU/8000 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 11 [ 20]: a=rtpmap:9 G722/8000 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 13 [ 15]: a=fmtp:101 0-15 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 14 [ 82]: a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:gluXdO/fvpC5mEy2qioJKQW6/6gPd4FggJo5iT3d [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 15 [ 82]: a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:acEYpw764FyrKO4qQ1LNZUArWcZXyRhfcR5V7YGO [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: --- (13 headers 16 lines) --- [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: = Looking for Call ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh (Checking From) --From tag 6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS --To-tag [2013-10-18 10:38:22] DEBUG[9655] acl.c: For destination '181.167.11.205', our source address is '192.168.3.50'. [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Target address 181.167.11.205:55169 is not local, substituting externaddr [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Setting SIP_TRANSPORT_TCP with address 190.220.68.151:5060 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Allocating new SIP dialog for 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh - INVITE (No RTP) [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [2013-10-18 10:38:22] DEBUG[9655] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces, 100rel, timer, norefersub" [2013-10-18 10:38:22] DEBUG[9655] sip/reqresp_parser.c: Found SIP option: -replaces- [2013-10-18 10:38:22] DEBUG[9655] sip/reqresp_parser.c: Matched SIP option: replaces [2013-10-18 10:38:22] DEBUG[9655] sip/reqresp_parser.c: Found SIP option: -100rel- [2013-10-18 10:38:22] DEBUG[9655] sip/reqresp_parser.c: Matched SIP option: 100rel [2013-10-18 10:38:22] DEBUG[9655] sip/reqresp_parser.c: Found SIP option: -timer- [2013-10-18 10:38:22] DEBUG[9655] sip/reqresp_parser.c: Matched SIP option: timer [2013-10-18 10:38:22] DEBUG[9655] sip/reqresp_parser.c: Found SIP option: -norefersub- [2013-10-18 10:38:22] DEBUG[9655] sip/reqresp_parser.c: Matched SIP option: norefersub [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: Splitting '181.167.11.205:55169' into... [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: ...host '181.167.11.205' and port '55169'. [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Sending to 181.167.11.205:55169 (NAT) [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Initializing initreq for method INVITE - callid 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Using INVITE request as basis request - 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: Splitting '190.220.68.151' into... [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: ...host '190.220.68.151' and port ''. [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found peer '2035' for '2035' from 181.167.11.205:55169 [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: <--- Reliably Transmitting (NAT) to 181.167.11.205:55169 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/TCP 181.167.11.205:55169;branch=z9hG4bKPjUde03fQ1sSJqVXjhgdWvr3JJ4.Rs8Jby;alias;received=181.167.11.205;rport=55169 From: "2035" ;tag=6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS To: sip:2000@190.220.68.151;tag=as7de84c39 Call-ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh CSeq: 27178 INVITE Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="7940bda9" Content-Length: 0 <------------> [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Trying to put 'SIP/2.0 401' onto TCP socket destined for 181.167.11.205:55169 [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Scheduling destruction of SIP dialog '7eJ.a8gRfobioCA15uC62w9JPXhhJBVh' in 23232 ms (Method: INVITE) [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: <--- SIP read from TCP:181.167.11.205:55169 ---> ACK sip:2000@190.220.68.151:14000 SIP/2.0 Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjUde03fQ1sSJqVXjhgdWvr3JJ4.Rs8Jby;alias Max-Forwards: 70 From: "2035" ;tag=6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS To: sip:2000@190.220.68.151;tag=as7de84c39 Call-ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh CSeq: 27178 ACK Content-Length: 0 <-------------> [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 0 [ 41]: ACK sip:2000@190.220.68.151:14000 SIP/2.0 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 1 [ 98]: Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjUde03fQ1sSJqVXjhgdWvr3JJ4.Rs8Jby;alias [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 3 [ 75]: From: "2035" ;tag=6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 4 [ 42]: To: sip:2000@190.220.68.151;tag=as7de84c39 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 5 [ 41]: Call-ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 6 [ 15]: CSeq: 27178 ACK [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: --- (8 headers 0 lines) --- [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: = Looking for Call ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh (Checking From) --From tag 6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS --To-tag as7de84c39 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Stopping retransmission on '7eJ.a8gRfobioCA15uC62w9JPXhhJBVh' of Response 27178: Match Not Found [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: <--- SIP read from TCP:181.167.11.205:55169 ---> INVITE sip:2000@190.220.68.151:14000 SIP/2.0 Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjxQLFqj4AqRZ5Zy2VFesdRdLpYoUU2Cks;alias Max-Forwards: 70 From: "2035" ;tag=6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS To: sip:2000@190.220.68.151 Contact: Call-ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh CSeq: 27179 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub User-Agent: Bria Android 2.3.6 Authorization: Digest username="2035", realm="asterisk", nonce="7940bda9", uri="sip:2000@190.220.68.151:14000", response="f3862776e59856df1c064b192519e070", algorithm=MD5 Content-Type: application/sdp Content-Length: 473 v=0 o=- 3591092302 3591092302 IN IP4 192.168.2.101 s=cpc_med c=IN IP4 192.168.2.101 t=0 0 m=audio 4002 RTP/SAVP 18 0 8 9 101 a=sendrecv a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:gluXdO/fvpC5mEy2qioJKQW6/6gPd4FggJo5iT3d a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:acEYpw764FyrKO4qQ1LNZUArWcZXyRhfcR5V7YGO <-------------> [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 0 [ 44]: INVITE sip:2000@190.220.68.151:14000 SIP/2.0 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 1 [ 98]: Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjxQLFqj4AqRZ5Zy2VFesdRdLpYoUU2Cks;alias [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 3 [ 75]: From: "2035" ;tag=6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 4 [ 27]: To: sip:2000@190.220.68.151 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 5 [ 57]: Contact: [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 6 [ 41]: Call-ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 7 [ 18]: CSeq: 27179 INVITE [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 8 [ 96]: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 9 [ 46]: Supported: replaces, 100rel, timer, norefersub [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 10 [ 30]: User-Agent: Bria Android 2.3.6 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 11 [170]: Authorization: Digest username="2035", realm="asterisk", nonce="7940bda9", uri="sip:2000@190.220.68.151:14000", response="f3862776e59856df1c064b192519e070", algorithm=MD5 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 13 [ 19]: Content-Length: 473 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 14 [ 0]: [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 0 [ 3]: v=0 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 1 [ 46]: o=- 3591092302 3591092302 IN IP4 192.168.2.101 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 2 [ 9]: s=cpc_med [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 3 [ 22]: c=IN IP4 192.168.2.101 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 4 [ 5]: t=0 0 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 5 [ 34]: m=audio 4002 RTP/SAVP 18 0 8 9 101 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 6 [ 10]: a=sendrecv [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 7 [ 21]: a=rtpmap:18 G729/8000 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 8 [ 19]: a=fmtp:18 annexb=no [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 9 [ 20]: a=rtpmap:0 PCMU/8000 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 11 [ 20]: a=rtpmap:9 G722/8000 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 13 [ 15]: a=fmtp:101 0-15 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 14 [ 82]: a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:gluXdO/fvpC5mEy2qioJKQW6/6gPd4FggJo5iT3d [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Body 15 [ 82]: a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:acEYpw764FyrKO4qQ1LNZUArWcZXyRhfcR5V7YGO [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: --- (14 headers 16 lines) --- [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: = Looking for Call ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh (Checking From) --From tag 6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS --To-tag [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: Splitting '190.220.68.151:14000' into... [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: ...host '190.220.68.151' and port '14000'. [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: Splitting '190.220.68.151:14000' into... [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: ...host '190.220.68.151' and port '14000'. [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: Splitting '181.167.11.205:55169' into... [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: ...host '181.167.11.205' and port '55169'. [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Sending to 181.167.11.205:55169 (NAT) [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Initializing initreq for method INVITE - callid 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Using INVITE request as basis request - 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: Splitting '190.220.68.151' into... [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: ...host '190.220.68.151' and port ''. [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found peer '2035' for '2035' from 181.167.11.205:55169 [2013-10-18 10:38:22] DEBUG[9655] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f30bc819c78' [2013-10-18 10:38:22] DEBUG[9655] res_rtp_asterisk.c: Allocated port 10002 for RTP instance '0x7f30bc819c78' [2013-10-18 10:38:22] DEBUG[9655] rtp_engine.c: RTP instance '0x7f30bc819c78' is setup and ready to go [2013-10-18 10:38:22] DEBUG[9655] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f30bc74a8f8' [2013-10-18 10:38:22] DEBUG[9655] res_rtp_asterisk.c: Allocated port 10024 for RTP instance '0x7f30bc74a8f8' [2013-10-18 10:38:22] DEBUG[9655] rtp_engine.c: RTP instance '0x7f30bc74a8f8' is setup and ready to go [2013-10-18 10:38:22] DEBUG[9655] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f30bc74a8f8' [2013-10-18 10:38:22] VERBOSE[9655] netsock2.c: == Using SIP VIDEO CoS mark 6 [2013-10-18 10:38:22] DEBUG[9655] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f30bc819c78' [2013-10-18 10:38:22] VERBOSE[9655] netsock2.c: == Using SIP RTP CoS mark 5 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Setting NAT on RTP to On [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Setting NAT on VRTP to On [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing session-level SDP o=- 3591092302 3591092302 IN IP4 192.168.2.101... OK. [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing session-level SDP s=cpc_med... UNSUPPORTED OR FAILED. [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: Splitting '192.168.2.101' into... [2013-10-18 10:38:22] DEBUG[9655] netsock2.c: ...host '192.168.2.101' and port ''. [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.2.101... OK. [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found RTP audio format 18 [2013-10-18 10:38:22] DEBUG[9655] rtp_engine.c: Setting payload 18 based on m type on 0x7f309de890a0 [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found RTP audio format 0 [2013-10-18 10:38:22] DEBUG[9655] rtp_engine.c: Setting payload 0 based on m type on 0x7f309de890a0 [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found RTP audio format 8 [2013-10-18 10:38:22] DEBUG[9655] rtp_engine.c: Setting payload 8 based on m type on 0x7f309de890a0 [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found RTP audio format 9 [2013-10-18 10:38:22] DEBUG[9655] rtp_engine.c: Setting payload 9 based on m type on 0x7f309de890a0 [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found RTP audio format 101 [2013-10-18 10:38:22] DEBUG[9655] rtp_engine.c: Setting payload 101 based on m type on 0x7f309de890a0 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found audio description format G729 for ID 18 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED OR FAILED. [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found audio description format PCMU for ID 0 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found audio description format PCMA for ID 8 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found audio description format G722 for ID 9 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Found audio description format telephone-event for ID 101 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [2013-10-18 10:38:22] DEBUG[9655] sip/sdp_crypto.c: local_key64 IvLsrF9SuBsxYPmpUcUlJL/LloK3M9ZQ6vScKuYH len 40 [2013-10-18 10:38:22] WARNING[9655] sip/sdp_crypto.c: Could not set SRTP policies [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:gluXdO/fvpC5mEy2qioJKQW6/6gPd4FggJo5iT3d... UNSUPPORTED OR FAILED. [2013-10-18 10:38:22] WARNING[9655] sip/sdp_crypto.c: Could not set SRTP policies [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Processing media-level (audio) SDP a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:acEYpw764FyrKO4qQ1LNZUArWcZXyRhfcR5V7YGO... UNSUPPORTED OR FAILED. [2013-10-18 10:38:22] WARNING[9655] chan_sip.c: Rejecting secure audio stream without encryption details: audio 4002 RTP/SAVP 18 0 8 9 101 [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: <--- Reliably Transmitting (NAT) to 181.167.11.205:55169 ---> SIP/2.0 488 Not acceptable here Via: SIP/2.0/TCP 181.167.11.205:55169;branch=z9hG4bKPjxQLFqj4AqRZ5Zy2VFesdRdLpYoUU2Cks;alias;received=181.167.11.205;rport=55169 From: "2035" ;tag=6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS To: sip:2000@190.220.68.151;tag=as7de84c39 Call-ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh CSeq: 27179 INVITE Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Trying to put 'SIP/2.0 488' onto TCP socket destined for 181.167.11.205:55169 [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: Scheduling destruction of SIP dialog '7eJ.a8gRfobioCA15uC62w9JPXhhJBVh' in 23232 ms (Method: INVITE) [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: No compatible codecs for this SIP call. [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: SIP message could not be handled, bad request: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: <--- SIP read from TCP:181.167.11.205:55169 ---> ACK sip:2000@190.220.68.151:14000 SIP/2.0 Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjxQLFqj4AqRZ5Zy2VFesdRdLpYoUU2Cks;alias Max-Forwards: 70 From: "2035" ;tag=6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS To: sip:2000@190.220.68.151;tag=as7de84c39 Call-ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh CSeq: 27179 ACK Content-Length: 0 <-------------> [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 0 [ 41]: ACK sip:2000@190.220.68.151:14000 SIP/2.0 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 1 [ 98]: Via: SIP/2.0/TCP 181.167.11.205:55169;rport;branch=z9hG4bKPjxQLFqj4AqRZ5Zy2VFesdRdLpYoUU2Cks;alias [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 3 [ 75]: From: "2035" ;tag=6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 4 [ 42]: To: sip:2000@190.220.68.151;tag=as7de84c39 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 5 [ 41]: Call-ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 6 [ 15]: CSeq: 27179 ACK [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2013-10-18 10:38:22] VERBOSE[9655] chan_sip.c: --- (8 headers 0 lines) --- [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: = Looking for Call ID: 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh (Checking From) --From tag 6Eukp7iaLQLQSuG8eRDuHGs2yjSaJgMS --To-tag as7de84c39 [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [2013-10-18 10:38:22] DEBUG[9655] chan_sip.c: Stopping retransmission on '7eJ.a8gRfobioCA15uC62w9JPXhhJBVh' of Response 27179: Match Not Found [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:200.81.44.95:59671 ---> REGISTER sip:mtssolutions.dyndns.org:14000;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 10.122.193.244:5060;branch=z9hG4bK-d8754z-f27060707292eeac-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=6295f44e Call-ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. CSeq: 146 REGISTER Expires: 60 Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri User-Agent: Zoiper r20066 Authorization: Digest username="2020",realm="asterisk",nonce="37894f27",uri="sip:mtssolutions.dyndns.org:14000;transport=UDP",response="c38c3e158d3ba7b0d03a662b8b22bb45",algorithm=MD5 Allow-Events: presence, kpml Content-Length: 0 <-------------> [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 0 [ 64]: REGISTER sip:mtssolutions.dyndns.org:14000;transport=UDP SIP/2.0 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 1 [ 87]: Via: SIP/2.0/UDP 10.122.193.244:5060;branch=z9hG4bK-d8754z-f27060707292eeac-1---d8754z- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 3 [ 80]: Contact: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 4 [ 58]: To: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 5 [ 73]: From: ;tag=6295f44e [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 6 [ 53]: Call-ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 7 [ 18]: CSeq: 146 REGISTER [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 8 [ 11]: Expires: 60 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 10 [ 74]: Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 11 [ 25]: User-Agent: Zoiper r20066 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 12 [183]: Authorization: Digest username="2020",realm="asterisk",nonce="37894f27",uri="sip:mtssolutions.dyndns.org:14000;transport=UDP",response="c38c3e158d3ba7b0d03a662b8b22bb45",algorithm=MD5 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 13 [ 28]: Allow-Events: presence, kpml [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 14 [ 17]: Content-Length: 0 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: --- (15 headers 0 lines) --- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: = Looking for Call ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. (Checking From) --From tag 6295f44e --To-tag [2013-10-18 10:38:24] DEBUG[3380] acl.c: For destination '200.81.44.95', our source address is '192.168.3.50'. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Target address 200.81.44.95:59671 is not local, substituting externaddr [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. - REGISTER (No RTP) [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Initializing initreq for method REGISTER - callid NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: Splitting '10.122.193.244:5060' into... [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: ...host '10.122.193.244' and port '5060'. [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Sending to 200.81.44.95:59671 (NAT) [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: Splitting 'mtssolutions.dyndns.org:14000' into... [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: ...host 'mtssolutions.dyndns.org' and port ''. [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: <--- Transmitting (NAT) to 200.81.44.95:59671 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.122.193.244:5060;branch=z9hG4bK-d8754z-f27060707292eeac-1---d8754z-;received=200.81.44.95;rport=59671 From: ;tag=6295f44e To: ;tag=as05a7698c Call-ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. CSeq: 146 REGISTER Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="440140d9" Content-Length: 0 <------------> [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 200.81.44.95:59671 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Scheduling destruction of SIP dialog 'NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ.' in 32000 ms (Method: REGISTER) [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:200.81.44.95:59671 ---> REGISTER sip:mtssolutions.dyndns.org:14000;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 10.122.193.244:5060;branch=z9hG4bK-d8754z-f27060707292eeac-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=6295f44e Call-ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. CSeq: 146 REGISTER Expires: 60 Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri User-Agent: Zoiper r20066 Authorization: Digest username="2020",realm="asterisk",nonce="37894f27",uri="sip:mtssolutions.dyndns.org:14000;transport=UDP",response="c38c3e158d3ba7b0d03a662b8b22bb45",algorithm=MD5 Allow-Events: presence, kpml Content-Length: 0 <-------------> [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 0 [ 64]: REGISTER sip:mtssolutions.dyndns.org:14000;transport=UDP SIP/2.0 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 1 [ 87]: Via: SIP/2.0/UDP 10.122.193.244:5060;branch=z9hG4bK-d8754z-f27060707292eeac-1---d8754z- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 3 [ 80]: Contact: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 4 [ 58]: To: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 5 [ 73]: From: ;tag=6295f44e [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 6 [ 53]: Call-ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 7 [ 18]: CSeq: 146 REGISTER [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 8 [ 11]: Expires: 60 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 10 [ 74]: Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 11 [ 25]: User-Agent: Zoiper r20066 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 12 [183]: Authorization: Digest username="2020",realm="asterisk",nonce="37894f27",uri="sip:mtssolutions.dyndns.org:14000;transport=UDP",response="c38c3e158d3ba7b0d03a662b8b22bb45",algorithm=MD5 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 13 [ 28]: Allow-Events: presence, kpml [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 14 [ 17]: Content-Length: 0 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: --- (15 headers 0 lines) --- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: = Looking for Call ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. (Checking From) --From tag 6295f44e --To-tag [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: Splitting 'mtssolutions.dyndns.org:14000' into... [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: ...host 'mtssolutions.dyndns.org' and port '14000'. [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: Splitting 'mtssolutions.dyndns.org:14000' into... [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: ...host 'mtssolutions.dyndns.org' and port '14000'. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Ignoring SIP message because of retransmit (REGISTER Seqno 146, ours 146) [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Initializing initreq for method REGISTER - callid NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: Splitting '10.122.193.244:5060' into... [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: ...host '10.122.193.244' and port '5060'. [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Sending to 200.81.44.95:59671 (NAT) [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: Splitting 'mtssolutions.dyndns.org:14000' into... [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: ...host 'mtssolutions.dyndns.org' and port ''. [2013-10-18 10:38:24] NOTICE[3380] chan_sip.c: Correct auth, but based on stale nonce received from ';tag=6295f44e' [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: <--- Transmitting (NAT) to 200.81.44.95:59671 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.122.193.244:5060;branch=z9hG4bK-d8754z-f27060707292eeac-1---d8754z-;received=200.81.44.95;rport=59671 From: ;tag=6295f44e To: ;tag=as05a7698c Call-ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. CSeq: 146 REGISTER Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="440140d9", stale=true Content-Length: 0 <------------> [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 200.81.44.95:59671 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Scheduling destruction of SIP dialog 'NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ.' in 32000 ms (Method: REGISTER) [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:200.81.44.95:59671 ---> REGISTER sip:mtssolutions.dyndns.org:14000;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 10.122.193.244:5060;branch=z9hG4bK-d8754z-a10456f681bc8991-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=6295f44e Call-ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. CSeq: 147 REGISTER Expires: 60 Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri User-Agent: Zoiper r20066 Authorization: Digest username="2020",realm="asterisk",nonce="440140d9",uri="sip:mtssolutions.dyndns.org:14000;transport=UDP",response="fae0f1aaf3a7224aa40af491dee36bb9",algorithm=MD5 Allow-Events: presence, kpml Content-Length: 0 <-------------> [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 0 [ 64]: REGISTER sip:mtssolutions.dyndns.org:14000;transport=UDP SIP/2.0 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 1 [ 87]: Via: SIP/2.0/UDP 10.122.193.244:5060;branch=z9hG4bK-d8754z-a10456f681bc8991-1---d8754z- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 3 [ 80]: Contact: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 4 [ 58]: To: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 5 [ 73]: From: ;tag=6295f44e [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 6 [ 53]: Call-ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 7 [ 18]: CSeq: 147 REGISTER [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 8 [ 11]: Expires: 60 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 10 [ 74]: Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 11 [ 25]: User-Agent: Zoiper r20066 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 12 [183]: Authorization: Digest username="2020",realm="asterisk",nonce="440140d9",uri="sip:mtssolutions.dyndns.org:14000;transport=UDP",response="fae0f1aaf3a7224aa40af491dee36bb9",algorithm=MD5 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 13 [ 28]: Allow-Events: presence, kpml [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 14 [ 17]: Content-Length: 0 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: --- (15 headers 0 lines) --- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: = Looking for Call ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. (Checking From) --From tag 6295f44e --To-tag [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: Splitting 'mtssolutions.dyndns.org:14000' into... [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: ...host 'mtssolutions.dyndns.org' and port '14000'. [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: Splitting 'mtssolutions.dyndns.org:14000' into... [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: ...host 'mtssolutions.dyndns.org' and port '14000'. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Initializing initreq for method REGISTER - callid NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: Splitting '10.122.193.244:5060' into... [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: ...host '10.122.193.244' and port '5060'. [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Sending to 200.81.44.95:59671 (NAT) [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: Splitting 'mtssolutions.dyndns.org:14000' into... [2013-10-18 10:38:24] DEBUG[3380] netsock2.c: ...host 'mtssolutions.dyndns.org' and port ''. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Store REGISTER's src-IP:port for call routing. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 5f8f09f35385a9f847872fc9291117c0@192.168.3.50:14000 - OPTIONS (No RTP) [2013-10-18 10:38:24] DEBUG[3380] acl.c: For destination '200.81.44.95', our source address is '192.168.3.50'. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Target address 200.81.44.95:59671 is not local, substituting externaddr [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: SIP call-id changed from '5f8f09f35385a9f847872fc9291117c0@192.168.3.50:14000' to '3a43939333720c144221da5b3b639649@190.220.68.151:14000' [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Initializing initreq for method OPTIONS - callid 3a43939333720c144221da5b3b639649@190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 0 [ 85]: OPTIONS sip:2020@10.122.193.244:5060;rinstance=5c85dd8f9e199070;transport=UDP SIP/2.0 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK0c5a12dd;rport [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 3 [ 67]: From: "asterisk" ;tag=as4b58e978 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 4 [ 75]: To: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 5 [ 44]: Contact: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 6 [ 62]: Call-ID: 3a43939333720c144221da5b3b639649@190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 9 [ 35]: Date: Fri, 18 Oct 2013 13:38:24 GMT [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Reliably Transmitting (NAT) to 200.81.44.95:59671: OPTIONS sip:2020@10.122.193.244:5060;rinstance=5c85dd8f9e199070;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK0c5a12dd;rport Max-Forwards: 70 From: "asterisk" ;tag=as4b58e978 To: Contact: Call-ID: 3a43939333720c144221da5b3b639649@190.220.68.151:14000 CSeq: 102 OPTIONS User-Agent: PBX Date: Fri, 18 Oct 2013 13:38:24 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #84890 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 200.81.44.95:59671 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: <--- Transmitting (NAT) to 200.81.44.95:59671 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.122.193.244:5060;branch=z9hG4bK-d8754z-a10456f681bc8991-1---d8754z-;received=200.81.44.95;rport=59671 From: ;tag=6295f44e To: ;tag=as05a7698c Call-ID: NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ. CSeq: 147 REGISTER Server: PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Expires: 60 Contact: ;expires=60 Date: Fri, 18 Oct 2013 13:38:24 GMT Content-Length: 0 <------------> [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 200.81.44.95:59671 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 2c3d485833c5855967f9394c29d9c5be@192.168.3.50:14000 - NOTIFY (No RTP) [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2013-10-18 10:38:24] DEBUG[3380] acl.c: For destination '200.81.44.95', our source address is '192.168.3.50'. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Target address 200.81.44.95:59671 is not local, substituting externaddr [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: SIP call-id changed from '2c3d485833c5855967f9394c29d9c5be@192.168.3.50:14000' to '42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000' [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Scheduling destruction of SIP dialog '42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000' in 7360 ms (Method: NOTIFY) [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Initializing initreq for method NOTIFY - callid 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 0 [ 84]: NOTIFY sip:2020@10.122.193.244:5060;rinstance=5c85dd8f9e199070;transport=UDP SIP/2.0 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK40a1767f;rport [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 3 [ 67]: From: "asterisk" ;tag=as7f05be43 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 4 [ 75]: To: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 5 [ 44]: Contact: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 6 [ 62]: Call-ID: 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 7 [ 16]: CSeq: 102 NOTIFY [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 9 [ 22]: Event: message-summary [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 10 [ 48]: Content-Type: application/simple-message-summary [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Reliably Transmitting (NAT) to 200.81.44.95:59671: NOTIFY sip:2020@10.122.193.244:5060;rinstance=5c85dd8f9e199070;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK40a1767f;rport Max-Forwards: 70 From: "asterisk" ;tag=as7f05be43 To: Contact: Call-ID: 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 CSeq: 102 NOTIFY User-Agent: PBX Event: message-summary Content-Type: application/simple-message-summary Content-Length: 97 Messages-Waiting: no Message-Account: sip:*5555@190.220.68.151:14000 Voice-Message: 0/0 (0/0) --- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #84893 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 200.81.44.95:59671 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Scheduling destruction of SIP dialog 'NWNlMjhiNDU0NTJkYmE2MzU0MjY3YWJkMDVjZWQ2NTQ.' in 32000 ms (Method: REGISTER) [2013-10-18 10:38:24] DEBUG[3344] devicestate.c: No provider found, checking channel drivers for SIP - 2020 [2013-10-18 10:38:24] DEBUG[3344] chan_sip.c: Checking device state for peer 2020 [2013-10-18 10:38:24] DEBUG[3344] devicestate.c: Changing state for SIP/2020 - state 1 (Not in use) [2013-10-18 10:38:24] DEBUG[3344] devicestate.c: device 'SIP/2020' state '1' [2013-10-18 10:38:24] DEBUG[3395] app_queue.c: Device 'SIP/2020' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: SIP TIMER: Rescheduling retransmission #84893 (1) NOTIFY - 4 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 230 ms (t1 115 ms (Retrans id #84893)) [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Retransmitting #1 (NAT) to 200.81.44.95:59671: NOTIFY sip:2020@10.122.193.244:5060;rinstance=5c85dd8f9e199070;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK40a1767f;rport Max-Forwards: 70 From: "asterisk" ;tag=as7f05be43 To: Contact: Call-ID: 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 CSeq: 102 NOTIFY User-Agent: PBX Event: message-summary Content-Type: application/simple-message-summary Content-Length: 97 Messages-Waiting: no Message-Account: sip:*5555@190.220.68.151:14000 Voice-Message: 0/0 (0/0) --- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 200.81.44.95:59671 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:200.81.44.95:59671 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK0c5a12dd;rport=14000 Contact: To: ;tag=49aa5c6f From: "asterisk";tag=as4b58e978 Call-ID: 3a43939333720c144221da5b3b639649@190.220.68.151:14000 CSeq: 102 OPTIONS Accept: application/sdp, application/sdp Accept-Language: en Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri User-Agent: Zoiper r20066 Allow-Events: presence, kpml Content-Length: 0 <-------------> [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 1 [ 72]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK0c5a12dd;rport=14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 2 [ 34]: Contact: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 3 [ 88]: To: ;tag=49aa5c6f [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 4 [ 66]: From: "asterisk";tag=as4b58e978 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 5 [ 62]: Call-ID: 3a43939333720c144221da5b3b639649@190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 6 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 7 [ 40]: Accept: application/sdp, application/sdp [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 8 [ 19]: Accept-Language: en [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 10 [ 74]: Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 11 [ 25]: User-Agent: Zoiper r20066 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 12 [ 28]: Allow-Events: presence, kpml [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: --- (14 headers 0 lines) --- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: = Looking for Call ID: 3a43939333720c144221da5b3b639649@190.220.68.151:14000 (Checking To) --From tag as4b58e978 --To-tag 49aa5c6f [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #84890 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Stopping retransmission on '3a43939333720c144221da5b3b639649@190.220.68.151:14000' of Request 102: Match Found [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Destroying SIP dialog 3a43939333720c144221da5b3b639649@190.220.68.151:14000 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Really destroying SIP dialog '3a43939333720c144221da5b3b639649@190.220.68.151:14000' Method: OPTIONS [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:200.81.44.95:59671 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK40a1767f;rport=14000 Contact: To: ;tag=e26e0847 From: "asterisk";tag=as7f05be43 Call-ID: 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 CSeq: 102 NOTIFY User-Agent: Zoiper r20066 Content-Length: 0 <-------------> [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 1 [ 72]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK40a1767f;rport=14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 2 [ 34]: Contact: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 3 [ 88]: To: ;tag=e26e0847 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 4 [ 66]: From: "asterisk";tag=as7f05be43 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 5 [ 62]: Call-ID: 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 6 [ 16]: CSeq: 102 NOTIFY [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 7 [ 25]: User-Agent: Zoiper r20066 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: --- (9 headers 0 lines) --- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: = Looking for Call ID: 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 (Checking To) --From tag as7f05be43 --To-tag e26e0847 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #84893 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Stopping retransmission on '42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000' of Request 102: Match Found [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Got 200 accepted on NOTIFY 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Destroying SIP dialog 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Really destroying SIP dialog '42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000' Method: NOTIFY [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:200.81.44.95:59671 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK40a1767f;rport=14000 Contact: To: ;tag=e26e0847 From: "asterisk";tag=as7f05be43 Call-ID: 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 CSeq: 102 NOTIFY User-Agent: Zoiper r20066 Content-Length: 0 <-------------> [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 1 [ 72]: Via: SIP/2.0/UDP 190.220.68.151:14000;branch=z9hG4bK40a1767f;rport=14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 2 [ 34]: Contact: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 3 [ 88]: To: ;tag=e26e0847 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 4 [ 66]: From: "asterisk";tag=as7f05be43 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 5 [ 62]: Call-ID: 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 6 [ 16]: CSeq: 102 NOTIFY [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 7 [ 25]: User-Agent: Zoiper r20066 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: --- (9 headers 0 lines) --- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: = Looking for Call ID: 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 (Checking To) --From tag as7f05be43 --To-tag e26e0847 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: That's odd... Got a response on a call we don't know about. Callid 42790fa70ba9ec6c1625e4d64b7ea8f1@190.220.68.151:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Invalid SIP message - rejected , no callid, len 403 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 3b91c4e41fda3f8a280911f22f033685@192.168.3.50:14000 - OPTIONS (No RTP) [2013-10-18 10:38:24] DEBUG[3380] acl.c: For destination '192.168.3.254', our source address is '192.168.3.50'. [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.3.50:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: SIP call-id changed from '3b91c4e41fda3f8a280911f22f033685@192.168.3.50:14000' to '73e0a29a3915412933c0d95b395edd3c@192.168.3.50:14000' [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Initializing initreq for method OPTIONS - callid 73e0a29a3915412933c0d95b395edd3c@192.168.3.50:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 0 [ 57]: OPTIONS sip:2014@192.168.1.115:5066;transport=udp SIP/2.0 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 192.168.3.50:14000;branch=z9hG4bK7df72016;rport [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 3 [ 65]: From: "asterisk" ;tag=as73ecee36 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 4 [ 47]: To: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 5 [ 42]: Contact: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 6 [ 60]: Call-ID: 73e0a29a3915412933c0d95b395edd3c@192.168.3.50:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 9 [ 35]: Date: Fri, 18 Oct 2013 13:38:24 GMT [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Reliably Transmitting (NAT) to 192.168.3.254:1043: OPTIONS sip:2014@192.168.1.115:5066;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.3.50:14000;branch=z9hG4bK7df72016;rport Max-Forwards: 70 From: "asterisk" ;tag=as73ecee36 To: Contact: Call-ID: 73e0a29a3915412933c0d95b395edd3c@192.168.3.50:14000 CSeq: 102 OPTIONS User-Agent: PBX Date: Fri, 18 Oct 2013 13:38:24 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #84896 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.3.254:1043 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:192.168.3.254:1043 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.3.50:14000;branch=z9hG4bK7df72016;rport From: "asterisk" ;tag=as73ecee36 To: ;tag=ccfec490458aacd7 Call-ID: 73e0a29a3915412933c0d95b395edd3c@192.168.3.50:14000 CSeq: 102 OPTIONS User-Agent: Grandstream GXP2000 1.2.1.4 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Supported: replaces, timer Content-Length: 0 <-------------> [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 192.168.3.50:14000;branch=z9hG4bK7df72016;rport [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 2 [ 65]: From: "asterisk" ;tag=as73ecee36 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 3 [ 68]: To: ;tag=ccfec490458aacd7 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 4 [ 60]: Call-ID: 73e0a29a3915412933c0d95b395edd3c@192.168.3.50:14000 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 6 [ 39]: User-Agent: Grandstream GXP2000 1.2.1.4 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 7 [ 52]: Contact: [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 8 [ 85]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 9 [ 26]: Supported: replaces, timer [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: --- (11 headers 0 lines) --- [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: = Looking for Call ID: 73e0a29a3915412933c0d95b395edd3c@192.168.3.50:14000 (Checking To) --From tag as73ecee36 --To-tag ccfec490458aacd7 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #84896 [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Stopping retransmission on '73e0a29a3915412933c0d95b395edd3c@192.168.3.50:14000' of Request 102: Match Found [2013-10-18 10:38:24] DEBUG[3380] chan_sip.c: Destroying SIP dialog 73e0a29a3915412933c0d95b395edd3c@192.168.3.50:14000 [2013-10-18 10:38:24] VERBOSE[3380] chan_sip.c: Really destroying SIP dialog '73e0a29a3915412933c0d95b395edd3c@192.168.3.50:14000' Method: OPTIONS [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 2548d4b27ad657c1095cb9762b391684@192.168.3.50:14000 - OPTIONS (No RTP) [2013-10-18 10:38:25] DEBUG[3380] acl.c: For destination '192.168.3.254', our source address is '192.168.3.50'. [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.3.50:14000 [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: SIP call-id changed from '2548d4b27ad657c1095cb9762b391684@192.168.3.50:14000' to '593409e55582380e30ebffed6d1aeff0@192.168.3.50:14000' [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Initializing initreq for method OPTIONS - callid 593409e55582380e30ebffed6d1aeff0@192.168.3.50:14000 [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 0 [ 57]: OPTIONS sip:2013@192.168.1.111:5066;transport=udp SIP/2.0 [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 192.168.3.50:14000;branch=z9hG4bK4b103675;rport [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 3 [ 65]: From: "asterisk" ;tag=as77292d7e [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 4 [ 47]: To: [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 5 [ 42]: Contact: [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 6 [ 60]: Call-ID: 593409e55582380e30ebffed6d1aeff0@192.168.3.50:14000 [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 9 [ 35]: Date: Fri, 18 Oct 2013 13:38:25 GMT [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2013-10-18 10:38:25] VERBOSE[3380] chan_sip.c: Reliably Transmitting (NAT) to 192.168.3.254:1041: OPTIONS sip:2013@192.168.1.111:5066;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.3.50:14000;branch=z9hG4bK4b103675;rport Max-Forwards: 70 From: "asterisk" ;tag=as77292d7e To: Contact: Call-ID: 593409e55582380e30ebffed6d1aeff0@192.168.3.50:14000 CSeq: 102 OPTIONS User-Agent: PBX Date: Fri, 18 Oct 2013 13:38:25 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #84899 [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.3.254:1041 [2013-10-18 10:38:25] VERBOSE[3380] chan_sip.c: <--- SIP read from UDP:192.168.3.254:1041 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.3.50:14000;branch=z9hG4bK4b103675;rport From: "asterisk" ;tag=as77292d7e To: ;tag=fc55e49c6c2e6c1a Call-ID: 593409e55582380e30ebffed6d1aeff0@192.168.3.50:14000 CSeq: 102 OPTIONS User-Agent: Grandstream GXP2000 1.2.1.4 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Supported: replaces, timer Content-Length: 0 <-------------> [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 1 [ 64]: Via: SIP/2.0/UDP 192.168.3.50:14000;branch=z9hG4bK4b103675;rport [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 2 [ 65]: From: "asterisk" ;tag=as77292d7e [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 3 [ 68]: To: ;tag=fc55e49c6c2e6c1a [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 4 [ 60]: Call-ID: 593409e55582380e30ebffed6d1aeff0@192.168.3.50:14000 [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 6 [ 39]: User-Agent: Grandstream GXP2000 1.2.1.4 [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 7 [ 52]: Contact: [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 8 [ 85]: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 9 [ 26]: Supported: replaces, timer [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2013-10-18 10:38:25] VERBOSE[3380] chan_sip.c: --- (11 headers 0 lines) --- [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: = Looking for Call ID: 593409e55582380e30ebffed6d1aeff0@192.168.3.50:14000 (Checking To) --From tag as77292d7e --To-tag fc55e49c6c2e6c1a [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #84899 [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Stopping retransmission on '593409e55582380e30ebffed6d1aeff0@192.168.3.50:14000' of Request 102: Match Found [2013-10-18 10:38:25] DEBUG[3380] chan_sip.c: Destroying SIP dialog 593409e55582380e30ebffed6d1aeff0@192.168.3.50:14000 [2013-10-18 10:38:25] VERBOSE[3380] chan_sip.c: Really destroying SIP dialog '593409e55582380e30ebffed6d1aeff0@192.168.3.50:14000' Method: OPTIONS [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 474fa2534439620e02ade7101b5275db@192.168.3.50:14000 - OPTIONS (No RTP) [2013-10-18 10:38:26] DEBUG[3380] acl.c: For destination '181.167.11.205', our source address is '192.168.3.50'. [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Target address 181.167.11.205:55169 is not local, substituting externaddr [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_TCP with address 190.220.68.151:5060 [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: SIP call-id changed from '474fa2534439620e02ade7101b5275db@192.168.3.50:14000' to '680b7acf02e8cfed453d942210877a16@190.220.68.151:5060' [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Initializing initreq for method OPTIONS - callid 680b7acf02e8cfed453d942210877a16@190.220.68.151:5060 [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 0 [ 62]: OPTIONS sip:2035@181.167.11.205:55169;transport=TCP;ob SIP/2.0 [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/TCP 190.220.68.151:5060;branch=z9hG4bK517b4c8b;rport [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as46bf76ce [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 4 [ 52]: To: [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 5 [ 57]: Contact: [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 6 [ 61]: Call-ID: 680b7acf02e8cfed453d942210877a16@190.220.68.151:5060 [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 8 [ 15]: User-Agent: PBX [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 9 [ 35]: Date: Fri, 18 Oct 2013 13:38:26 GMT [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2013-10-18 10:38:26] VERBOSE[3380] chan_sip.c: Reliably Transmitting (NAT) to 181.167.11.205:55169: OPTIONS sip:2035@181.167.11.205:55169;transport=TCP;ob SIP/2.0 Via: SIP/2.0/TCP 190.220.68.151:5060;branch=z9hG4bK517b4c8b;rport Max-Forwards: 70 From: "asterisk" ;tag=as46bf76ce To: Contact: Call-ID: 680b7acf02e8cfed453d942210877a16@190.220.68.151:5060 CSeq: 102 OPTIONS User-Agent: PBX Date: Fri, 18 Oct 2013 13:38:26 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 --- [2013-10-18 10:38:26] DEBUG[3380] chan_sip.c: Trying to put 'OPTIONS sip' onto TCP socket destined for 181.167.11.205:55169 [2013-10-18 10:38:26] VERBOSE[9655] chan_sip.c: <--- SIP read from TCP:181.167.11.205:55169 ---> SIP/2.0 200 OK Via: SIP/2.0/TCP 190.220.68.151:5060;rport=14000;received=190.220.68.151;branch=z9hG4bK517b4c8b Call-ID: 680b7acf02e8cfed453d942210877a16@190.220.68.151:5060 From: "asterisk" ;tag=as46bf76ce To: ;tag=z9hG4bK517b4c8b CSeq: 102 OPTIONS Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain, text/html, application/sopi-address-book Supported: replaces, 100rel, timer, norefersub Allow-Events: presence, message-summary, refer, address-book User-Agent: Bria Android 2.3.6 Content-Type: application/sdp Content-Length: 305 v=0 o=- 3591092306 3591092306 IN IP4 192.168.2.101 s=cpc_med t=0 0 m=audio 38026 RTP/AVP 18 0 8 9 101 c=IN IP4 192.168.2.101 a=sendrecv a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 1 [ 95]: Via: SIP/2.0/TCP 190.220.68.151:5060;rport=14000;received=190.220.68.151;branch=z9hG4bK517b4c8b [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 2 [ 61]: Call-ID: 680b7acf02e8cfed453d942210877a16@190.220.68.151:5060 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as46bf76ce [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 4 [ 52]: To: ;tag=z9hG4bK517b4c8b [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 6 [ 96]: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 7 [219]: Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain, text/html, application/sopi-address-book [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 8 [ 46]: Supported: replaces, 100rel, timer, norefersub [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 9 [ 60]: Allow-Events: presence, message-summary, refer, address-book [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 10 [ 30]: User-Agent: Bria Android 2.3.6 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 11 [ 29]: Content-Type: application/sdp [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 12 [ 19]: Content-Length: 305 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Header 13 [ 0]: [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 0 [ 3]: v=0 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 1 [ 46]: o=- 3591092306 3591092306 IN IP4 192.168.2.101 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 2 [ 9]: s=cpc_med [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 3 [ 5]: t=0 0 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 4 [ 34]: m=audio 38026 RTP/AVP 18 0 8 9 101 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 5 [ 22]: c=IN IP4 192.168.2.101 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 6 [ 10]: a=sendrecv [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 7 [ 21]: a=rtpmap:18 G729/8000 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 8 [ 19]: a=fmtp:18 annexb=no [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 9 [ 20]: a=rtpmap:0 PCMU/8000 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 11 [ 20]: a=rtpmap:9 G722/8000 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: Body 13 [ 15]: a=fmtp:101 0-15 [2013-10-18 10:38:26] VERBOSE[9655] chan_sip.c: --- (13 headers 14 lines) --- [2013-10-18 10:38:26] DEBUG[9655] chan_sip.c: = Looking for Call ID: 680b7acf02e8cfed453d942210877a16@190.220.68.151:5060 (Checking To) --From tag as46bf76ce --To-tag z9hG4bK517b4c8b [2013-10-18 10:38:27] DEBUG[3380] chan_sip.c: Destroying SIP dialog 680b7acf02e8cfed453d942210877a16@190.220.68.151:5060 [2013-10-18 10:38:27] VERBOSE[3380] chan_sip.c: Really destroying SIP dialog '680b7acf02e8cfed453d942210877a16@190.220.68.151:5060' Method: OPTIONS [2013-10-18 10:38:34] DEBUG[3380] chan_sip.c: Auto destroying SIP dialog 'oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K' [2013-10-18 10:38:34] DEBUG[3380] chan_sip.c: Destroying SIP dialog oNNjde-X8ti4xMaMTjHIZ3jOTHsRry.K [2013-10-18 10:38:34] DEBUG[3380] rtp_engine.c: Destroyed RTP instance '0x7f30bc738f18' [2013-10-18 10:38:34] DEBUG[3380] rtp_engine.c: Destroyed RTP instance '0x7f30bc741028' [2013-10-18 10:38:36] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 439475a237d738384119c87c12732cd9@192.168.3.50:14000 - OPTIONS (No RTP) [2013-10-18 10:38:36] DEBUG[3380] acl.c: For destination '192.168.3.254', our source address is '192.168.3.50'. [2013-10-18 10:38:36] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.3.50:14000 [2013-10-18 10:38:36] DEBUG[3380] chan_sip.c: SIP call-id changed from '439475a237d738384119c87c12732cd9@192.168.3.50:14000' to '55711c4f2fe27ad9170ac3831e8e003e@192.168.3.50:14000' [2013-10-18 10:38:36] DEBUG[3380] chan_sip.c: Initializing initreq for method OPTIONS - callid 55711c4f2fe27ad9170ac3831e8e003e@192.168.3.50:14000 [2013-10-18 10:38:36] DEBUG[3380] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.3.254:1042 [2013-10-18 10:38:36] DEBUG[3380] chan_sip.c: = Looking for Call ID: 55711c4f2fe27ad9170ac3831e8e003e@192.168.3.50:14000 (Checking To) --From tag as5dfb1266 --To-tag 4e47432485dd4f6e [2013-10-18 10:38:36] DEBUG[3380] chan_sip.c: Stopping retransmission on '55711c4f2fe27ad9170ac3831e8e003e@192.168.3.50:14000' of Request 102: Match Found [2013-10-18 10:38:36] DEBUG[3380] chan_sip.c: Destroying SIP dialog 55711c4f2fe27ad9170ac3831e8e003e@192.168.3.50:14000 [2013-10-18 10:38:37] DEBUG[3380] chan_sip.c: Auto destroying SIP dialog '9836c9e3a3f1f4f4@192.168.1.64' [2013-10-18 10:38:37] DEBUG[3380] chan_sip.c: Destroying SIP dialog 9836c9e3a3f1f4f4@192.168.1.64 [2013-10-18 10:38:42] DEBUG[3380] chan_sip.c: Auto destroying SIP dialog 'NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY.' [2013-10-18 10:38:42] DEBUG[3380] chan_sip.c: Destroying SIP dialog NzMxMjg3MzAwNzc4OTI4OWZmNjk3NTFmZDQwMjdhZmY. [2013-10-18 10:38:45] DEBUG[3380] chan_sip.c: Auto destroying SIP dialog '7eJ.a8gRfobioCA15uC62w9JPXhhJBVh' [2013-10-18 10:38:45] DEBUG[3380] chan_sip.c: Destroying SIP dialog 7eJ.a8gRfobioCA15uC62w9JPXhhJBVh [2013-10-18 10:38:45] DEBUG[3380] rtp_engine.c: Destroyed RTP instance '0x7f30bc819c78' [2013-10-18 10:38:45] DEBUG[3380] rtp_engine.c: Destroyed RTP instance '0x7f30bc74a8f8' [2013-10-18 10:38:47] DEBUG[3380] chan_sip.c: Allocating new SIP dialog for 70d5a3a9140a010d3058f35315cb4cfd@192.168.3.50:14000 - OPTIONS (No RTP) [2013-10-18 10:38:47] DEBUG[3380] acl.c: For destination '181.167.11.205', our source address is '192.168.3.50'. [2013-10-18 10:38:47] DEBUG[3380] chan_sip.c: Target address 181.167.11.205:5064 is not local, substituting externaddr [2013-10-18 10:38:47] DEBUG[3380] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 190.220.68.151:14000 [2013-10-18 10:38:47] DEBUG[3380] chan_sip.c: SIP call-id changed from '70d5a3a9140a010d3058f35315cb4cfd@192.168.3.50:14000' to '0b1aa7332ed7bb7873d8c50510982280@190.220.68.151:14000' [2013-10-18 10:38:47] DEBUG[3380] chan_sip.c: Initializing initreq for method OPTIONS - callid 0b1aa7332ed7bb7873d8c50510982280@190.220.68.151:14000 [2013-10-18 10:38:47] DEBUG[3380] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 181.167.11.205:5064 [2013-10-18 10:38:47] DEBUG[3380] chan_sip.c: = Looking for Call ID: 0b1aa7332ed7bb7873d8c50510982280@190.220.68.151:14000 (Checking To) --From tag as2e80ea97 --To-tag 201445e4d7490832i2 [2013-10-18 10:38:47] DEBUG[3380] chan_sip.c: Stopping retransmission on '0b1aa7332ed7bb7873d8c50510982280@190.220.68.151:14000' of Request 102: Match Found [2013-10-18 10:38:47] DEBUG[3380] chan_sip.c: Destroying SIP dialog 0b1aa7332ed7bb7873d8c50510982280@190.220.68.151:14000 [2013-10-18 10:40:28] NOTICE[3380] chan_sip.c: Peer '2020' is now UNREACHABLE! Last qualify: 121 [2013-10-18 10:40:32] NOTICE[3380] chan_sip.c: Peer '2020' is now Reachable. (157ms / 2000ms)