*CLI> core set debug 100 Core debug was 19 and is now 100 *CLI> core set verbose 100 Verbosity was 19 and is now 100 *CLI> *CLI> *CLI> sip set debug 100 SIP Debugging enabled *CLI> *CLI> *CLI> *CLI> *CLI> *CLI> *CLI> *CLI> *CLI> <--- SIP read from 195.94.224.220:54462 ---> INVITE sip:74952232731@195.94.224.196:5060;user=phone SIP/2.0 Via: SIP/2.0/UDP 195.94.224.220:5060 From: ;tag=1125ADB4-F19 To: Date: Tue, 27 Mar 2007 12:04:55 GMT Call-ID: 3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220 Supported: 100rel Cisco-Guid: 910580194-3683783131-3020671348-1358234525 User-Agent: Cisco-SIPGateway/IOS-12.x CSeq: 101 INVITE Max-Forwards: 6 Timestamp: 1174997095 Contact: Expires: 180 Content-Type: application/sdp Content-Length: 242 v=0 o=CiscoSystemsSIP-GW-UserAgent 7408 5077 IN IP4 195.94.224.220 s=SIP Call c=IN IP4 195.94.224.220 t=0 0 m=audio 18700 RTP/AVP 18 8 101 a=rtpmap:18 G729/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 0 [ 61]: INVITE sip:74952232731@195.94.224.196:5060;user=phone SIP/2.0 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 1 [ 37]: Via: SIP/2.0/UDP 195.94.224.220:5060 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 2 [ 54]: From: ;tag=1125ADB4-F19 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 3 [ 47]: To: [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 4 [ 35]: Date: Tue, 27 Mar 2007 12:04:55 GMT [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 5 [ 59]: Call-ID: 3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 6 [ 17]: Supported: 100rel [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 7 [ 54]: Cisco-Guid: 910580194-3683783131-3020671348-1358234525 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 8 [ 37]: User-Agent: Cisco-SIPGateway/IOS-12.x [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 9 [ 16]: CSeq: 101 INVITE [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 10 [ 15]: Max-Forwards: 6 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 11 [ 21]: Timestamp: 1174997095 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 12 [ 56]: Contact: [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 13 [ 12]: Expires: 180 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 14 [ 29]: Content-Type: application/sdp [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 15 [ 19]: Content-Length: 242 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 16 [ 0]: [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Body 0 [ 3]: v=0 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Body 1 [ 62]: o=CiscoSystemsSIP-GW-UserAgent 7408 5077 IN IP4 195.94.224.220 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Body 2 [ 10]: s=SIP Call [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Body 3 [ 23]: c=IN IP4 195.94.224.220 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Body 4 [ 5]: t=0 0 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Body 5 [ 30]: m=audio 18700 RTP/AVP 18 8 101 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Body 6 [ 21]: a=rtpmap:18 G729/8000 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Body 9 [ 15]: a=fmtp:101 0-15 --- (16 headers 10 lines) --- [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:2844 do_setnat: Setting NAT on RTP to Off [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:2849 do_setnat: Setting NAT on VRTP to Off [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4665 sip_alloc: Allocating new SIP dialog for 3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220 - INVITE (With RTP) [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:15366 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:1831 parse_sip_options: Begin: parsing SIP "Supported: 100rel" [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:1839 parse_sip_options: Found SIP option: -100rel- [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:1845 parse_sip_options: Matched SIP option: 100rel Sending to 195.94.224.220 : 5060 (no NAT) [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:13996 handle_request_invite: Initializing initreq for method INVITE - callid 3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220 Using INVITE request as basis request - 3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220 [Mar 27 16:11:59] DEBUG[29130]: res_config_mysql.c:809 mysql_reconnect: MySQL RealTime: Everything is fine. [Mar 27 16:11:59] DEBUG[29130]: res_config_mysql.c:139 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip WHERE name = '4992711790' No user '4992711790' in SIP users list [Mar 27 16:11:59] DEBUG[29130]: res_config_mysql.c:809 mysql_reconnect: MySQL RealTime: Everything is fine. [Mar 27 16:11:59] DEBUG[29130]: res_config_mysql.c:139 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip WHERE host = '195.94.224.220' [Mar 27 16:11:59] DEBUG[29130]: res_config_mysql.c:809 mysql_reconnect: MySQL RealTime: Everything is fine. [Mar 27 16:11:59] DEBUG[29130]: res_config_mysql.c:139 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip WHERE ipaddr = '195.94.224.220' No matching peer for '4992711790' from '195.94.224.220:54462' [Mar 27 16:11:59] NOTICE[29130]: chan_sip.c:14038 handle_request_invite: Failed to authenticate user ;tag=1125ADB4-F19 <--- Reliably Transmitting (no NAT) to 195.94.224.220:5060 ---> SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 195.94.224.220:5060;received=195.94.224.220 From: ;tag=1125ADB4-F19 To: ;tag=as4e8c4d93 Call-ID: 3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220 CSeq: 101 INVITE User-Agent: Asterisk PBX SVN-trunk-r57993M Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:2117 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1 Scheduling destruction of SIP dialog '3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220' in 32000 ms (Method: INVITE) <--- SIP read from 195.94.224.220:54462 ---> ACK sip:74952232731@195.94.224.196:5060;user=phone SIP/2.0 Via: SIP/2.0/UDP 195.94.224.220:5060 From: ;tag=1125ADB4-F19 To: ;tag=as4e8c4d93 Date: Tue, 27 Mar 2007 12:04:55 GMT Call-ID: 3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220 Max-Forwards: 6 Content-Length: 0 CSeq: 101 ACK <-------------> [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 0 [ 58]: ACK sip:74952232731@195.94.224.196:5060;user=phone SIP/2.0 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 1 [ 37]: Via: SIP/2.0/UDP 195.94.224.220:5060 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 2 [ 54]: From: ;tag=1125ADB4-F19 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 3 [ 62]: To: ;tag=as4e8c4d93 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 4 [ 35]: Date: Tue, 27 Mar 2007 12:04:55 GMT [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 5 [ 59]: Call-ID: 3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 6 [ 15]: Max-Forwards: 6 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 7 [ 17]: Content-Length: 0 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 8 [ 13]: CSeq: 101 ACK [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4943 parse_request: Header 9 [ 0]: --- (9 headers 0 lines) --- [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:4729 find_call: = Found Their Call ID: 3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220 Their Tag Our tag: as4e8c4d93 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:15366 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:2225 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1 [Mar 27 16:11:59] DEBUG[29130]: chan_sip.c:2236 __sip_ack: Stopping retransmission on '3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220' of Response 101: Match Found Really destroying SIP dialog '3646F60A-DB9211DB-B40DC974-50F5039D@195.94.224.220' Method: ACK