[root@atk tmp]# cat sipdebug-CL-enabled.txt Parsing /etc/asterisk/asterisk.conf Parsing /etc/asterisk/extconfig.conf [Nov 9 13:06:44] == Parsing '/etc/asterisk/asterisk.conf': [Nov 9 13:06:44] Found [Nov 9 13:06:44] == Parsing '/etc/asterisk/extconfig.conf': [Nov 9 13:06:44] Found [Nov 9 13:06:44] Asterisk 1.2.13, Copyright (C) 1999 - 2006 Digium, Inc. and others. [Nov 9 13:06:44] Created by Mark Spencer [Nov 9 13:06:44] Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details. [Nov 9 13:06:44] This is free software, with components licensed under the GNU General Public [Nov 9 13:06:44] License version 2 and other licenses; you are welcome to redistribute it under [Nov 9 13:06:44] certain conditions. Type 'show license' for details. [Nov 9 13:06:44] ========================================================================= [Nov 9 13:06:44] Connected to Asterisk 1.2.13 currently running on atk (pid = 15590) Verbosity was 4 and is now 5 Core debug was 4 and is now 5 atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> show hints atk*CLI> -= Registered Asterisk Dial Plan Hints =- 2003 : SIP/laboratorio-2003 State:Unavailable Watchers 0 2002 : SIP/laboratorio-2002 State:Idle Watchers 0 2001 : SIP/laboratorio-2001 State:Idle Watchers 0 ---------------- - 3 hints registered atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> -- Accepting call from '5537372321' to '5551485202' on channel 0/28, span 1 Nov 9 13:06:58 DEBUG[15605]: chan_zap.c:1403 zt_enable_ec: Enabled echo cancellation on channel 28 Nov 9 13:06:58 DEBUG[15594]: devicestate.c:187 do_state_change: Changing state for Zap/28 - state 2 (In use) Nov 9 13:06:58 DEBUG[15640]: pbx.c:1677 pbx_extension_helper: Launching 'SetAccount' -- Executing SetAccount("Zap/28-1", "laboratorio-in") in new stack Nov 9 13:06:58 DEBUG[15640]: pbx.c:1677 pbx_extension_helper: Launching 'Goto' -- Executing Goto("Zap/28-1", "2002|1") in new stack -- Goto (laboratorio,2002,1) Nov 9 13:06:58 DEBUG[15640]: pbx.c:1677 pbx_extension_helper: Launching 'SetMusicOnHold' -- Executing SetMusicOnHold("Zap/28-1", "laboratorio") in new stack Nov 9 13:06:58 DEBUG[15640]: db.c:200 ast_db_get: Unable to find key '2002' in family 'laboratorio-VIPA' Nov 9 13:06:58 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0' Nov 9 13:06:58 DEBUG[15640]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0' Nov 9 13:06:58 DEBUG[15640]: pbx.c:1677 pbx_extension_helper: Launching 'GotoIf' -- Executing GotoIf("Zap/28-1", "0?3:5") in new stack -- Goto (laboratorio,2002,5) Nov 9 13:06:58 DEBUG[15640]: db.c:200 ast_db_get: Unable to find key '2002' in family 'laboratorio-CFIM' Nov 9 13:06:58 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0' Nov 9 13:06:58 DEBUG[15640]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0' Nov 9 13:06:58 DEBUG[15640]: pbx.c:1677 pbx_extension_helper: Launching 'GotoIf' -- Executing GotoIf("Zap/28-1", "0?6:7") in new stack -- Goto (laboratorio,2002,7) Nov 9 13:06:58 DEBUG[15640]: pbx.c:1677 pbx_extension_helper: Launching 'Dial' -- Executing Dial("Zap/28-1", "SIP/laboratorio-2002&SIP/laboratorio-2002s|20|r") in new stack Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3168 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:1885 create_addr_from_peer: Setting NAT on RTP to 524288 Nov 9 13:06:58 DEBUG[15640]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-2002-7. Nov 9 13:06:58 DEBUG[15640]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-2002-5. Nov 9 13:06:58 DEBUG[15640]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-2002-2. Nov 9 13:06:58 DEBUG[15640]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-2002-1. Nov 9 13:06:58 DEBUG[15640]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-5551485202-2. Nov 9 13:06:58 DEBUG[15640]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-5551485202-1. Nov 9 13:06:58 DEBUG[15640]: channel.c:2902 ast_channel_inherit_variables: Not copying variable CALLEDTON. Nov 9 13:06:58 DEBUG[15640]: channel.c:2902 ast_channel_inherit_variables: Not copying variable ANI2. Nov 9 13:06:58 DEBUG[15640]: channel.c:2902 ast_channel_inherit_variables: Not copying variable TRANSFERCAPABILITY. Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:2079 sip_call: Outgoing Call for laboratorio-2002 Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:2217 update_call_counter: Updating call counter for outgoing call Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:2272 update_call_counter: Call to user 'laboratorio-2002' is 1 out of 2 We're at 201.148.150.58 port 15286 Adding codec 0x4 (ulaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 0: INVITE sip:laboratorio-2002@200.57.67.55:22776 SIP/2.0 (54) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK259ffbce;rport (65) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 2: From: "5537372321" ;tag=as6212ad55 (66) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 3: To: (45) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 4: Contact: (40) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 5: Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx (57) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 6: CSeq: 102 INVITE (16) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 7: User-Agent: Asterisk PBX (24) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 8: Max-Forwards: 70 (16) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 9: Date: Thu, 09 Nov 2006 19:06:58 GMT (35) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 11: Content-Type: application/sdp (29) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 12: Content-Length: 220 (19) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3392 parse_request: Header 13: (0) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3424 parse_request: Line: v=0 (3) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3424 parse_request: Line: o=root 15590 15590 IN IP4 201.148.150.58 (40) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3424 parse_request: Line: s=session (9) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3424 parse_request: Line: c=IN IP4 201.148.150.58 (23) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3424 parse_request: Line: t=0 0 (5) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3424 parse_request: Line: m=audio 15286 RTP/AVP 0 101 (27) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3424 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3424 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3424 parse_request: Line: a=fmtp:101 0-16 (15) Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3424 parse_request: Line: a=silenceSupp:off - - - - (25) 13 headers, 10 lines Reliably Transmitting (NAT) to 200.57.67.55:22776: INVITE sip:laboratorio-2002@200.57.67.55:22776 SIP/2.0 Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK259ffbce;rport From: "5537372321" ;tag=as6212ad55 To: Contact: Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 09 Nov 2006 19:06:58 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 220 v=0 o=root 15590 15590 IN IP4 201.148.150.58 s=session c=IN IP4 201.148.150.58 t=0 0 m=audio 15286 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:1304 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #33 -- Called laboratorio-2002 Nov 9 13:06:58 DEBUG[15640]: chan_sip.c:3168 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Nov 9 13:06:58 DEBUG[15641]: app_queue.c:500 changethread: Device 'Zap/28' changed to state '2' (In use) but we don't care because they're not a member of any queue. Nov 9 13:06:58 WARNING[15640]: chan_sip.c:1991 create_addr: No such host: laboratorio-2002s Destroying call '149b2924793e2d6e1bd22da2143d6960@127.0.0.1' Nov 9 13:06:58 NOTICE[15640]: app_dial.c:1056 dial_exec_full: Unable to create channel of type 'SIP' (cause 3 - No route to destination) Nov 9 13:06:58 DEBUG[15640]: chan_zap.c:4817 zt_indicate: Requested indication 3 on channel Zap/28-1 Nov 9 13:06:58 DEBUG[15594]: channel.c:777 channel_find_locked: Avoiding initial deadlock for 'Zap/28-1' Nov 9 13:06:58 DEBUG[15594]: devicestate.c:187 do_state_change: Changing state for Zap/28 - state 6 (Ringing) Nov 9 13:06:58 DEBUG[15642]: app_queue.c:500 changethread: Device 'Zap/28' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. atk*CLI> <-- SIP read from 200.57.67.55:22776: SIP/2.0 100 Trying Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK259ffbce;rport From: "5537372321" ;tag=as6212ad55 To: Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx Date: Thu, 09 Nov 2006 19:07:01 GMT CSeq: 102 INVITE Server: Cisco-CP7940G/7.5 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE Content-Length: 0 Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 0: SIP/2.0 100 Trying (18) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK259ffbce;rport (65) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 2: From: "5537372321" ;tag=as6212ad55 (66) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 3: To: (45) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 4: Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx (57) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 5: Date: Thu, 09 Nov 2006 19:07:01 GMT (35) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 6: CSeq: 102 INVITE (16) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 7: Server: Cisco-CP7940G/7.5 (25) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 8: Contact: (50) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE (65) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 10: Content-Length: 0 (17) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 11: (0) --- (11 headers 0 lines) --- Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3216 find_call: = Found Their Call ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx Their Tag Our tag: as6212ad55 Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:1456 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #33 - INVITE (got response) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:1465 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx' Request 102: Found Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:9642 handle_response_invite: SIP response 100 to standard invite atk*CLI> <-- SIP read from 200.57.67.55:22776: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK259ffbce;rport From: "5537372321" ;tag=as6212ad55 To: ;tag=000bbe404a2f180f12a0a57e-3173ee5c Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx Date: Thu, 09 Nov 2006 19:07:01 GMT CSeq: 102 INVITE Server: Cisco-CP7940G/7.5 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE Content-Length: 0 Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 0: SIP/2.0 180 Ringing (19) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK259ffbce;rport (65) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 2: From: "5537372321" ;tag=as6212ad55 (66) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 3: To: ;tag=000bbe404a2f180f12a0a57e-3173ee5c (83) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 4: Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx (57) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 5: Date: Thu, 09 Nov 2006 19:07:01 GMT (35) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 6: CSeq: 102 INVITE (16) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 7: Server: Cisco-CP7940G/7.5 (25) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 8: Contact: (50) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE (65) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 10: Content-Length: 0 (17) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 11: (0) --- (11 headers 0 lines) --- Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3216 find_call: = Found Their Call ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx Their Tag Our tag: as6212ad55 Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:1465 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx' Request 102: Found Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:9642 handle_response_invite: SIP response 180 to standard invite -- SIP/laboratorio-2002-08befe00 is ringing Nov 9 13:06:58 DEBUG[15594]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:06:58 DEBUG[15594]: devicestate.c:187 do_state_change: Changing state for SIP/laboratorio-2002 - state 1 (Not in use) Nov 9 13:06:58 DEBUG[15594]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:06:58 DEBUG[15643]: app_queue.c:500 changethread: Device 'SIP/laboratorio-2002' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3168 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 0: OPTIONS sip:laboratorio-2001@200.57.67.55:15696 SIP/2.0 (55) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK1c63e1b8;rport (65) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 2: From: "asterisk" ;tag=as039bd43a (61) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 3: To: (45) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 4: Contact: (38) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 5: Call-ID: 5b8eff5f3454b7a3158b0f9e0c0e8efd@201.148.150.58 (56) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 6: CSeq: 102 OPTIONS (17) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 7: User-Agent: Asterisk PBX (24) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 8: Max-Forwards: 70 (16) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 9: Date: Thu, 09 Nov 2006 19:06:58 GMT (35) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 11: Content-Length: 0 (17) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 12: (0) 12 headers, 0 lines Reliably Transmitting (NAT) to 200.57.67.55:15696: OPTIONS sip:laboratorio-2001@200.57.67.55:15696 SIP/2.0 Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK1c63e1b8;rport From: "asterisk" ;tag=as039bd43a To: Contact: Call-ID: 5b8eff5f3454b7a3158b0f9e0c0e8efd@201.148.150.58 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 09 Nov 2006 19:06:58 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:1304 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #35 atk*CLI> <-- SIP read from 200.57.67.55:15696: SIP/2.0 200 OK Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK1c63e1b8;rport From: "asterisk" ;tag=as039bd43a To: ;tag=d28e56bbfc63dd3c Call-ID: 5b8eff5f3454b7a3158b0f9e0c0e8efd@201.148.150.58 CSeq: 102 OPTIONS User-Agent: Grandstream GXP2000 1.1.1.14 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Supported: replaces, timer Content-Length: 0 Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 0: SIP/2.0 200 OK (14) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK1c63e1b8;rport (65) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 2: From: "asterisk" ;tag=as039bd43a (61) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 3: To: ;tag=d28e56bbfc63dd3c (66) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 4: Call-ID: 5b8eff5f3454b7a3158b0f9e0c0e8efd@201.148.150.58 (56) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 5: CSeq: 102 OPTIONS (17) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 6: User-Agent: Grandstream GXP2000 1.1.1.14 (40) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 7: Contact: (50) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE (85) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 9: Supported: replaces, timer (26) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 10: Content-Length: 0 (17) Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 11: (0) --- (11 headers 0 lines) --- Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:3216 find_call: = Found Their Call ID: 5b8eff5f3454b7a3158b0f9e0c0e8efd@201.148.150.58 Their Tag Our tag: as039bd43a Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:1401 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #35 Nov 9 13:06:58 DEBUG[15609]: chan_sip.c:1412 __sip_ack: Stopping retransmission on '5b8eff5f3454b7a3158b0f9e0c0e8efd@201.148.150.58' of Request 102: Match Found Destroying call '5b8eff5f3454b7a3158b0f9e0c0e8efd@201.148.150.58' Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3168 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 0: OPTIONS sip:laboratorio-2002@200.57.67.55:22776 SIP/2.0 (55) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK2c19d2bf;rport (65) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 2: From: "asterisk" ;tag=as36b47e3a (61) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 3: To: (45) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 4: Contact: (38) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 5: Call-ID: 1e2b1e523b9673bc588c84710555c0c5@201.148.150.58 (56) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 6: CSeq: 102 OPTIONS (17) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 7: User-Agent: Asterisk PBX (24) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 8: Max-Forwards: 70 (16) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 9: Date: Thu, 09 Nov 2006 19:06:59 GMT (35) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 11: Content-Length: 0 (17) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 12: (0) 12 headers, 0 lines Reliably Transmitting (NAT) to 200.57.67.55:22776: OPTIONS sip:laboratorio-2002@200.57.67.55:22776 SIP/2.0 Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK2c19d2bf;rport From: "asterisk" ;tag=as36b47e3a To: Contact: Call-ID: 1e2b1e523b9673bc588c84710555c0c5@201.148.150.58 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 09 Nov 2006 19:06:59 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:1304 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #38 atk*CLI> <-- SIP read from 200.57.67.55:22776: SIP/2.0 200 OK Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK2c19d2bf;rport From: "asterisk" ;tag=as36b47e3a To: ;tag=000bbe404a2f18101d3719fb-1762fefc Call-ID: 1e2b1e523b9673bc588c84710555c0c5@201.148.150.58 Date: Thu, 09 Nov 2006 19:07:01 GMT CSeq: 102 OPTIONS Server: Cisco-CP7940G/7.5 Content-Length: 0 Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE Allow-Events: kpml,dialog,refer Accept: application/sdp,multipart/mixed,multipart/alternative Accept-Encoding: identity Accept-Language: en Supported: replaces Content-Length: 216 Content-Type: application/sdp Content-Disposition: session;handling=optional v=0 o=Cisco-SIPUA 22438 0 IN IP4 10.100.6.160 s=SIP Call t=0 0 m=audio 0 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 0: SIP/2.0 200 OK (14) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK2c19d2bf;rport (65) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 2: From: "asterisk" ;tag=as36b47e3a (61) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 3: To: ;tag=000bbe404a2f18101d3719fb-1762fefc (83) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 4: Call-ID: 1e2b1e523b9673bc588c84710555c0c5@201.148.150.58 (56) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 5: Date: Thu, 09 Nov 2006 19:07:01 GMT (35) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 6: CSeq: 102 OPTIONS (17) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 7: Server: Cisco-CP7940G/7.5 (25) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 8: Content-Length: 0 (17) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE (65) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 10: Allow-Events: kpml,dialog,refer (31) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 11: Accept: application/sdp,multipart/mixed,multipart/alternative (61) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 12: Accept-Encoding: identity (25) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 13: Accept-Language: en (19) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 14: Supported: replaces (19) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 15: Content-Length: 216 (19) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 16: Content-Type: application/sdp (29) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 17: Content-Disposition: session;handling=optional (46) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 18: (0) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: v=0 (3) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: o=Cisco-SIPUA 22438 0 IN IP4 10.100.6.160 (41) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: s=SIP Call (10) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: t=0 0 (5) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: m=audio 0 RTP/AVP 0 8 18 101 (28) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: a=rtpmap:18 G729/8000 (21) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: a=fmtp:101 0-15 (15) --- (18 headers 10 lines) --- Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:3216 find_call: = Found Their Call ID: 1e2b1e523b9673bc588c84710555c0c5@201.148.150.58 Their Tag Our tag: as36b47e3a Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:1401 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #38 Nov 9 13:06:59 DEBUG[15609]: chan_sip.c:1412 __sip_ack: Stopping retransmission on '1e2b1e523b9673bc588c84710555c0c5@201.148.150.58' of Request 102: Match Found Destroying call '1e2b1e523b9673bc588c84710555c0c5@201.148.150.58' atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> show hints atk*CLI> -= Registered Asterisk Dial Plan Hints =- 2003 : SIP/laboratorio-2003 State:Unavailable Watchers 0 2002 : SIP/laboratorio-2002 State:Idle Watchers 0 2001 : SIP/laboratorio-2001 State:Idle Watchers 0 ---------------- - 3 hints registered atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> <-- SIP read from 200.57.67.55:22776: SIP/2.0 200 OK Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK259ffbce;rport From: "5537372321" ;tag=as6212ad55 To: ;tag=000bbe404a2f180f12a0a57e-3173ee5c Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx Date: Thu, 09 Nov 2006 19:07:08 GMT CSeq: 102 INVITE Server: Cisco-CP7940G/7.5 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE Supported: replaces Content-Length: 205 Content-Type: application/sdp Content-Disposition: session;handling=optional v=0 o=Cisco-SIPUA 20644 0 IN IP4 10.100.6.160 s=SIP Call t=0 0 m=audio 22256 RTP/AVP 0 101 c=IN IP4 10.100.6.160 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 0: SIP/2.0 200 OK (14) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK259ffbce;rport (65) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 2: From: "5537372321" ;tag=as6212ad55 (66) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 3: To: ;tag=000bbe404a2f180f12a0a57e-3173ee5c (83) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 4: Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx (57) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 5: Date: Thu, 09 Nov 2006 19:07:08 GMT (35) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 6: CSeq: 102 INVITE (16) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 7: Server: Cisco-CP7940G/7.5 (25) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 8: Contact: (50) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE (65) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 10: Supported: replaces (19) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 11: Content-Length: 205 (19) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 12: Content-Type: application/sdp (29) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 13: Content-Disposition: session;handling=optional (46) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 14: (0) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: v=0 (3) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: o=Cisco-SIPUA 20644 0 IN IP4 10.100.6.160 (41) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: s=SIP Call (10) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: t=0 0 (5) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: m=audio 22256 RTP/AVP 0 101 (27) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: c=IN IP4 10.100.6.160 (21) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: a=fmtp:101 0-15 (15) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3424 parse_request: Line: a=sendrecv (10) --- (14 headers 10 lines) --- Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3216 find_call: = Found Their Call ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx Their Tag 000bbe404a2f180f12a0a57e-3173ee5c Our tag: as6212ad55 Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:1390 __sip_ack: Acked pending invite 102 Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:1412 __sip_ack: Stopping retransmission on '117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx' of Request 102: Match Found Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:9642 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 0 Found RTP audio format 101 Peer audio RTP is at port 10.100.6.160:22256 Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:3631 process_sdp: Peer audio RTP is at port 10.100.6.160:22256 Found description format PCMU Found description format telephone-event Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Nov 9 13:07:06 DEBUG[15609]: chan_sip.c:6194 build_route: build_route: Contact hop: list_route: hop: set_destination: Parsing for address/port to send to set_destination: set destination to 200.57.67.55, port 22776 Transmitting (NAT) to 200.57.67.55:22776: ACK sip:laboratorio-2002@200.57.67.55:22776 SIP/2.0 Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK7f563af6;rport From: "5537372321" ;tag=as6212ad55 To: ;tag=000bbe404a2f180f12a0a57e-3173ee5c Contact: Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- -- SIP/laboratorio-2002-08befe00 answered Zap/28-1 Nov 9 13:07:06 DEBUG[15640]: chan_zap.c:4817 zt_indicate: Requested indication -1 on channel Zap/28-1 Nov 9 13:07:06 DEBUG[15640]: channel.c:2409 set_format: Set channel Zap/28-1 to read format slin Nov 9 13:07:06 DEBUG[15640]: channel.c:2409 set_format: Set channel SIP/laboratorio-2002-08befe00 to write format slin Nov 9 13:07:06 DEBUG[15640]: channel.c:2409 set_format: Set channel SIP/laboratorio-2002-08befe00 to read format slin Nov 9 13:07:06 DEBUG[15640]: channel.c:2409 set_format: Set channel Zap/28-1 to write format slin Nov 9 13:07:06 DEBUG[15594]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:07:06 DEBUG[15594]: devicestate.c:187 do_state_change: Changing state for SIP/laboratorio-2002 - state 1 (Not in use) Nov 9 13:07:06 DEBUG[15594]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:07:06 DEBUG[15594]: devicestate.c:187 do_state_change: Changing state for Zap/28 - state 2 (In use) Nov 9 13:07:06 DEBUG[15644]: app_queue.c:500 changethread: Device 'SIP/laboratorio-2002' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Nov 9 13:07:06 DEBUG[15645]: app_queue.c:500 changethread: Device 'Zap/28' changed to state '2' (In use) but we don't care because they're not a member of any queue. Nov 9 13:07:06 DEBUG[15640]: rtp.c:1359 ast_rtp_write: Ooh, format changed from unknown to ulaw atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> show hints atk*CLI> -= Registered Asterisk Dial Plan Hints =- 2003 : SIP/laboratorio-2003 State:Unavailable Watchers 0 2002 : SIP/laboratorio-2002 State:Idle Watchers 0 2001 : SIP/laboratorio-2001 State:Idle Watchers 0 ---------------- - 3 hints registered atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> -- Channel 0/28, span 1 got hangup request Nov 9 13:07:11 DEBUG[15640]: channel.c:3377 ast_generic_bridge: Didn't get a frame from channel: Zap/28-1 Nov 9 13:07:11 DEBUG[15640]: channel.c:3662 ast_channel_bridge: Bridge stops bridging channels Zap/28-1 and SIP/laboratorio-2002-08befe00 Nov 9 13:07:11 DEBUG[15640]: channel.c:1373 ast_hangup: Hanging up channel 'SIP/laboratorio-2002-08befe00' Nov 9 13:07:11 DEBUG[15640]: chan_sip.c:2427 sip_hangup: Hangup call SIP/laboratorio-2002-08befe00, SIP callid 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx) Nov 9 13:07:11 DEBUG[15640]: chan_sip.c:2435 sip_hangup: update_call_counter(laboratorio-2002) - decrement call limit counter Nov 9 13:07:11 DEBUG[15640]: chan_sip.c:2217 update_call_counter: Updating call counter for outgoing call Nov 9 13:07:11 DEBUG[15640]: chan_sip.c:2255 update_call_counter: Call to user 'laboratorio-2002' removed from call limit 2 Scheduling destruction of call '117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx' in 32000 ms set_destination: Parsing for address/port to send to set_destination: set destination to 200.57.67.55, port 22776 Reliably Transmitting (NAT) to 200.57.67.55:22776: BYE sip:laboratorio-2002@200.57.67.55:22776 SIP/2.0 Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK7b4af3ed;rport From: "5537372321" ;tag=as6212ad55 To: ;tag=000bbe404a2f180f12a0a57e-3173ee5c Contact: Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Nov 9 13:07:11 DEBUG[15640]: chan_sip.c:1304 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #42 Nov 9 13:07:11 DEBUG[15640]: app_dial.c:1635 dial_exec_full: Exiting with DIALSTATUS=ANSWER. Nov 9 13:07:11 DEBUG[15640]: pbx.c:2316 __ast_pbx_run: Spawn extension (laboratorio,2002,7) exited non-zero on 'Zap/28-1' == Spawn extension (laboratorio, 2002, 7) exited non-zero on 'Zap/28-1' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '5537372321' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '5537372321' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2002' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'laboratorio' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Zap/28-1' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/laboratorio-2002-08befe00' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Dial' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/laboratorio-2002&SIP/laboratorio-2002s|20|r' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-11-09 13:06:58' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-11-09 13:07:06' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-11-09 13:07:11' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '13' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '5' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'laboratorio-in' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1163099218.4' Nov 9 13:07:11 DEBUG[15640]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' Nov 9 13:07:11 DEBUG[15594]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:07:11 DEBUG[15594]: devicestate.c:187 do_state_change: Changing state for SIP/laboratorio-2002 - state 1 (Not in use) Nov 9 13:07:11 DEBUG[15594]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:07:11 DEBUG[15640]: cdr_addon_mysql.c:206 mysql_log: cdr_mysql: inserting a CDR record. Nov 9 13:07:11 DEBUG[15640]: cdr_addon_mysql.c:222 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,userfield) VALUES ('2006-11-09 13:06:58','5537372321','5537372321','2002','laboratorio', 'Zap/28-1','SIP/laboratorio-2002-08befe00','Dial','SIP/laboratorio-2002&SIP/laboratorio-2002s|20|r',13,5,'ANSWERED',3,'laboratorio-in','') Nov 9 13:07:11 DEBUG[15640]: channel.c:1373 ast_hangup: Hanging up channel 'Zap/28-1' Nov 9 13:07:11 DEBUG[15640]: chan_zap.c:2309 zt_hangup: zt_hangup(Zap/28-1) Nov 9 13:07:11 DEBUG[15640]: chan_zap.c:2861 zt_setoption: Set option AUDIO MODE, value: ON(1) on Zap/28-1 Nov 9 13:07:11 DEBUG[15640]: chan_zap.c:2342 zt_hangup: Hangup: channel: 28 index = 0, normal = 42, callwait = -1, thirdcall = -1 Nov 9 13:07:11 DEBUG[15640]: chan_zap.c:2491 zt_hangup: Not yet hungup... Calling hangup once with icause, and clearing call Nov 9 13:07:11 DEBUG[15640]: chan_zap.c:1435 zt_disable_ec: disabled echo cancellation on channel 28 Nov 9 13:07:11 DEBUG[15640]: chan_zap.c:2782 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/28-1 Nov 9 13:07:11 DEBUG[15640]: chan_zap.c:1372 update_conf: Updated conferencing on 28, with 0 conference users Nov 9 13:07:11 DEBUG[15640]: chan_zap.c:2857 zt_setoption: Set option AUDIO MODE, value: OFF(0) on Zap/28-1 Nov 9 13:07:11 DEBUG[15640]: chan_zap.c:1435 zt_disable_ec: disabled echo cancellation on channel 28 -- Hungup 'Zap/28-1' Nov 9 13:07:11 DEBUG[15594]: devicestate.c:187 do_state_change: Changing state for Zap/28 - state 0 (Unknown) Nov 9 13:07:11 DEBUG[15646]: app_queue.c:500 changethread: Device 'SIP/laboratorio-2002' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Nov 9 13:07:11 DEBUG[15647]: app_queue.c:500 changethread: Device 'Zap/28' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. atk*CLI> <-- SIP read from 200.57.67.55:22776: SIP/2.0 200 OK Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK7b4af3ed;rport From: "5537372321" ;tag=as6212ad55 To: ;tag=000bbe404a2f180f12a0a57e-3173ee5c Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx Date: Thu, 09 Nov 2006 19:07:14 GMT CSeq: 103 BYE Server: Cisco-CP7940G/7.5 Content-Length: 0 Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 0: SIP/2.0 200 OK (14) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK7b4af3ed;rport (65) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 2: From: "5537372321" ;tag=as6212ad55 (66) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 3: To: ;tag=000bbe404a2f180f12a0a57e-3173ee5c (83) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 4: Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx (57) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 5: Date: Thu, 09 Nov 2006 19:07:14 GMT (35) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 6: CSeq: 103 BYE (13) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 7: Server: Cisco-CP7940G/7.5 (25) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 8: Content-Length: 0 (17) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 9: (0) --- (9 headers 0 lines) --- Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3216 find_call: = Found Their Call ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx Their Tag 000bbe404a2f180f12a0a57e-3173ee5c Our tag: as6212ad55 Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:1401 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #42 Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:1412 __sip_ack: Stopping retransmission on '117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx' of Request 103: Match Found Destroying call '117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx' atk*CLI> <-- SIP read from 200.57.67.55:22776: SIP/2.0 200 OK Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK7b4af3ed;rport From: "5537372321" ;tag=as6212ad55 To: ;tag=000bbe404a2f180f12a0a57e-3173ee5c Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx Date: Thu, 09 Nov 2006 19:07:14 GMT CSeq: 103 BYE Server: Cisco-CP7940G/7.5 Content-Length: 0 Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 0: SIP/2.0 200 OK (14) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK7b4af3ed;rport (65) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 2: From: "5537372321" ;tag=as6212ad55 (66) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 3: To: ;tag=000bbe404a2f180f12a0a57e-3173ee5c (83) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 4: Call-ID: 117e582c1aa35f7c7c028126748aeb1a@metrored.com.mx (57) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 5: Date: Thu, 09 Nov 2006 19:07:14 GMT (35) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 6: CSeq: 103 BYE (13) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 7: Server: Cisco-CP7940G/7.5 (25) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 8: Content-Length: 0 (17) Nov 9 13:07:11 DEBUG[15609]: chan_sip.c:3392 parse_request: Header 9: (0) --- (9 headers 0 lines) --- atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> atk*CLI> exit [Nov 9 13:07:16] Executing last minute cleanups [Nov 9 13:07:16] Asterisk cleanly ending (0). Asterisk ending (0).