Parsing /etc/asterisk/asterisk.conf Parsing /etc/asterisk/extconfig.conf [Nov 9 13:03:46] == Parsing '/etc/asterisk/asterisk.conf': [Nov 9 13:03:46] Found [Nov 9 13:03:46] == Parsing '/etc/asterisk/extconfig.conf': [Nov 9 13:03:46] Found [Nov 9 13:03:46] Asterisk 1.2.13, Copyright (C) 1999 - 2006 Digium, Inc. and others. [Nov 9 13:03:46] Created by Mark Spencer [Nov 9 13:03:46] Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details. [Nov 9 13:03:46] This is free software, with components licensed under the GNU General Public [Nov 9 13:03:46] License version 2 and other licenses; you are welcome to redistribute it under [Nov 9 13:03:46] certain conditions. Type 'show license' for details. [Nov 9 13:03:46] ========================================================================= [Nov 9 13:03:46] Connected to Asterisk 1.2.13 currently running on atk (pid = 15513) Verbosity is at least 5 Core debug is at least 5 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> -- Accepting call from '5537372321' to '5551485202' on channel 0/26, span 1 Nov 9 13:03:57 DEBUG[15529]: chan_zap.c:1403 zt_enable_ec: Enabled echo cancellation on channel 26 Nov 9 13:03:57 DEBUG[15517]: devicestate.c:187 do_state_change: Changing state for Zap/26 - state 2 (In use) Nov 9 13:03:57 DEBUG[15577]: pbx.c:1677 pbx_extension_helper: Launching 'SetAccount' -- Executing SetAccount("Zap/26-1", "laboratorio-in") in new stack Nov 9 13:03:57 DEBUG[15577]: pbx.c:1677 pbx_extension_helper: Launching 'Goto' -- Executing Goto("Zap/26-1", "2002|1") in new stack -- Goto (laboratorio,2002,1) Nov 9 13:03:57 DEBUG[15577]: pbx.c:1677 pbx_extension_helper: Launching 'SetMusicOnHold' -- Executing SetMusicOnHold("Zap/26-1", "laboratorio") in new stack Nov 9 13:03:57 DEBUG[15577]: db.c:200 ast_db_get: Unable to find key '2002' in family 'laboratorio-VIPA' Nov 9 13:03:57 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0' Nov 9 13:03:57 DEBUG[15577]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0' Nov 9 13:03:57 DEBUG[15577]: pbx.c:1677 pbx_extension_helper: Launching 'GotoIf' -- Executing GotoIf("Zap/26-1", "0?3:5") in new stack -- Goto (laboratorio,2002,5) Nov 9 13:03:57 DEBUG[15577]: db.c:200 ast_db_get: Unable to find key '2002' in family 'laboratorio-CFIM' Nov 9 13:03:57 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0' Nov 9 13:03:57 DEBUG[15577]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0' Nov 9 13:03:57 DEBUG[15577]: pbx.c:1677 pbx_extension_helper: Launching 'GotoIf' -- Executing GotoIf("Zap/26-1", "0?6:7") in new stack -- Goto (laboratorio,2002,7) Nov 9 13:03:57 DEBUG[15577]: pbx.c:1677 pbx_extension_helper: Launching 'Dial' -- Executing Dial("Zap/26-1", "SIP/laboratorio-2002&SIP/laboratorio-2002s|20|r") in new stack Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3168 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:1885 create_addr_from_peer: Setting NAT on RTP to 524288 Nov 9 13:03:57 DEBUG[15577]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-2002-7. Nov 9 13:03:57 DEBUG[15577]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-2002-5. Nov 9 13:03:57 DEBUG[15577]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-2002-2. Nov 9 13:03:57 DEBUG[15577]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-2002-1. Nov 9 13:03:57 DEBUG[15577]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-5551485202-2. Nov 9 13:03:57 DEBUG[15577]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-laboratorio-5551485202-1. Nov 9 13:03:57 DEBUG[15577]: channel.c:2902 ast_channel_inherit_variables: Not copying variable CALLEDTON. Nov 9 13:03:57 DEBUG[15577]: channel.c:2902 ast_channel_inherit_variables: Not copying variable ANI2. Nov 9 13:03:57 DEBUG[15577]: channel.c:2902 ast_channel_inherit_variables: Not copying variable TRANSFERCAPABILITY. Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:2079 sip_call: Outgoing Call for laboratorio-2002 Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:2217 update_call_counter: Updating call counter for outgoing call We're at 201.148.150.58 port 11186 Adding codec 0x4 (ulaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 0: INVITE sip:laboratorio-2002@200.57.67.55:22776 SIP/2.0 (54) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK55a355c7;rport (65) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 2: From: "5537372321" ;tag=as689a314f (66) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 3: To: (45) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 4: Contact: (40) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 5: Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx (57) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 6: CSeq: 102 INVITE (16) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 7: User-Agent: Asterisk PBX (24) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 8: Max-Forwards: 70 (16) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 9: Date: Thu, 09 Nov 2006 19:03:57 GMT (35) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 11: Content-Type: application/sdp (29) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 12: Content-Length: 220 (19) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3392 parse_request: Header 13: (0) Nov 9 13:03:57 DEBUG[15578]: app_queue.c:500 changethread: Device 'Zap/26' changed to state '2' (In use) but we don't care because they're not a member of any queue. Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3424 parse_request: Line: v=0 (3) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3424 parse_request: Line: o=root 15513 15513 IN IP4 201.148.150.58 (40) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3424 parse_request: Line: s=session (9) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3424 parse_request: Line: c=IN IP4 201.148.150.58 (23) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3424 parse_request: Line: t=0 0 (5) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3424 parse_request: Line: m=audio 11186 RTP/AVP 0 101 (27) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3424 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3424 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3424 parse_request: Line: a=fmtp:101 0-16 (15) Nov 9 13:03:57 DEBUG[15577]: 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=z9hG4bK55a355c7;rport From: "5537372321" ;tag=as689a314f To: Contact: Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 09 Nov 2006 19:03:57 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 220 v=0 o=root 15513 15513 IN IP4 201.148.150.58 s=session c=IN IP4 201.148.150.58 t=0 0 m=audio 11186 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:03:57 DEBUG[15577]: chan_sip.c:1304 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #45 -- Called laboratorio-2002 Nov 9 13:03:57 DEBUG[15577]: chan_sip.c:3168 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Nov 9 13:03:57 WARNING[15577]: chan_sip.c:1991 create_addr: No such host: laboratorio-2002s Destroying call '673b5280313ec7605cbd3b0f59c8affe@127.0.0.1' Nov 9 13:03:57 NOTICE[15577]: app_dial.c:1056 dial_exec_full: Unable to create channel of type 'SIP' (cause 3 - No route to destination) Nov 9 13:03:57 DEBUG[15577]: chan_zap.c:4817 zt_indicate: Requested indication 3 on channel Zap/26-1 Nov 9 13:03:57 DEBUG[15517]: channel.c:777 channel_find_locked: Avoiding initial deadlock for 'Zap/26-1' Nov 9 13:03:57 DEBUG[15517]: devicestate.c:187 do_state_change: Changing state for Zap/26 - state 6 (Ringing) Nov 9 13:03:57 DEBUG[15579]: app_queue.c:500 changethread: Device 'Zap/26' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:1195 retrans_pkt: SIP TIMER: Rescheduling retransmission #45 (1) INVITE - 5 Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:1209 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 316 ms (t1 158 ms (Retrans id #45)) Retransmitting #1 (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=z9hG4bK55a355c7;rport From: "5537372321" ;tag=as689a314f To: Contact: Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 09 Nov 2006 19:03:57 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 220 v=0 o=root 15513 15513 IN IP4 201.148.150.58 s=session c=IN IP4 201.148.150.58 t=0 0 m=audio 11186 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- 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=z9hG4bK55a355c7;rport From: "5537372321" ;tag=as689a314f To: Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx Date: Thu, 09 Nov 2006 19:04:00 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:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 0: SIP/2.0 100 Trying (18) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK55a355c7;rport (65) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 2: From: "5537372321" ;tag=as689a314f (66) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 3: To: (45) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 4: Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx (57) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 5: Date: Thu, 09 Nov 2006 19:04:00 GMT (35) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 6: CSeq: 102 INVITE (16) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 7: Server: Cisco-CP7940G/7.5 (25) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 8: Contact: (50) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE (65) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 10: Content-Length: 0 (17) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 11: (0) --- (11 headers 0 lines) --- Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:3216 find_call: = Found Their Call ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx Their Tag Our tag: as689a314f Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:1456 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #45 - INVITE (got response) Nov 9 13:03:57 DEBUG[15532]: chan_sip.c:1465 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '6d5297e95ce1691f7fcba7797208f979@metrored.com.mx' Request 102: Found Nov 9 13:03:57 DEBUG[15532]: 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=z9hG4bK55a355c7;rport From: "5537372321" ;tag=as689a314f To: ;tag=000bbe404a2f18067675fb27-46753a9d Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx Date: Thu, 09 Nov 2006 19:04:00 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:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 0: SIP/2.0 180 Ringing (19) Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK55a355c7;rport (65) Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 2: From: "5537372321" ;tag=as689a314f (66) Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 3: To: ;tag=000bbe404a2f18067675fb27-46753a9d (83) Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 4: Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx (57) Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 5: Date: Thu, 09 Nov 2006 19:04:00 GMT (35) Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 6: CSeq: 102 INVITE (16) Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 7: Server: Cisco-CP7940G/7.5 (25) Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 8: Contact: (50) Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE (65) Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 10: Content-Length: 0 (17) Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 11: (0) --- (11 headers 0 lines) --- Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:3216 find_call: = Found Their Call ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx Their Tag Our tag: as689a314f Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:1465 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '6d5297e95ce1691f7fcba7797208f979@metrored.com.mx' Request 102: Found Nov 9 13:03:58 DEBUG[15532]: chan_sip.c:9642 handle_response_invite: SIP response 180 to standard invite -- SIP/laboratorio-2002-083cbc28 is ringing Nov 9 13:03:58 DEBUG[15517]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:03:58 DEBUG[15517]: devicestate.c:187 do_state_change: Changing state for SIP/laboratorio-2002 - state 6 (Ringing) Nov 9 13:03:58 DEBUG[15517]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:03:58 DEBUG[15580]: app_queue.c:500 changethread: Device 'SIP/laboratorio-2002' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. 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:Ringing 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> <-- SIP read from 200.57.67.55:22776: SIP/2.0 200 OK Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK55a355c7;rport From: "5537372321" ;tag=as689a314f To: ;tag=000bbe404a2f18067675fb27-46753a9d Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx Date: Thu, 09 Nov 2006 19:04:09 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 16309 0 IN IP4 10.100.6.160 s=SIP Call t=0 0 m=audio 22244 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:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 0: SIP/2.0 200 OK (14) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK55a355c7;rport (65) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 2: From: "5537372321" ;tag=as689a314f (66) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 3: To: ;tag=000bbe404a2f18067675fb27-46753a9d (83) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 4: Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx (57) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 5: Date: Thu, 09 Nov 2006 19:04:09 GMT (35) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 6: CSeq: 102 INVITE (16) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 7: Server: Cisco-CP7940G/7.5 (25) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 8: Contact: (50) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE (65) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 10: Supported: replaces (19) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 11: Content-Length: 205 (19) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 12: Content-Type: application/sdp (29) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 13: Content-Disposition: session;handling=optional (46) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 14: (0) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3424 parse_request: Line: v=0 (3) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3424 parse_request: Line: o=Cisco-SIPUA 16309 0 IN IP4 10.100.6.160 (41) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3424 parse_request: Line: s=SIP Call (10) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3424 parse_request: Line: t=0 0 (5) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3424 parse_request: Line: m=audio 22244 RTP/AVP 0 101 (27) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3424 parse_request: Line: c=IN IP4 10.100.6.160 (21) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3424 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3424 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3424 parse_request: Line: a=fmtp:101 0-15 (15) Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3424 parse_request: Line: a=sendrecv (10) --- (14 headers 10 lines) --- Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3216 find_call: = Found Their Call ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx Their Tag 000bbe404a2f18067675fb27-46753a9d Our tag: as689a314f Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:1390 __sip_ack: Acked pending invite 102 Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:1412 __sip_ack: Stopping retransmission on '6d5297e95ce1691f7fcba7797208f979@metrored.com.mx' of Request 102: Match Found Nov 9 13:04:06 DEBUG[15532]: 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:22244 Nov 9 13:04:06 DEBUG[15532]: chan_sip.c:3631 process_sdp: Peer audio RTP is at port 10.100.6.160:22244 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:04:06 DEBUG[15532]: 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=z9hG4bK47a97130;rport From: "5537372321" ;tag=as689a314f To: ;tag=000bbe404a2f18067675fb27-46753a9d Contact: Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- -- SIP/laboratorio-2002-083cbc28 answered Zap/26-1 Nov 9 13:04:06 DEBUG[15577]: chan_zap.c:4817 zt_indicate: Requested indication -1 on channel Zap/26-1 Nov 9 13:04:06 DEBUG[15577]: channel.c:2409 set_format: Set channel Zap/26-1 to read format slin Nov 9 13:04:06 DEBUG[15577]: channel.c:2409 set_format: Set channel SIP/laboratorio-2002-083cbc28 to write format slin Nov 9 13:04:06 DEBUG[15577]: channel.c:2409 set_format: Set channel SIP/laboratorio-2002-083cbc28 to read format slin Nov 9 13:04:06 DEBUG[15577]: channel.c:2409 set_format: Set channel Zap/26-1 to write format slin Nov 9 13:04:06 DEBUG[15517]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:04:06 DEBUG[15517]: devicestate.c:187 do_state_change: Changing state for SIP/laboratorio-2002 - state 2 (In use) Nov 9 13:04:06 DEBUG[15517]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:04:06 DEBUG[15517]: devicestate.c:187 do_state_change: Changing state for Zap/26 - state 2 (In use) Nov 9 13:04:06 DEBUG[15581]: app_queue.c:500 changethread: Device 'SIP/laboratorio-2002' changed to state '2' (In use) but we don't care because they're not a member of any queue. Nov 9 13:04:06 DEBUG[15582]: app_queue.c:500 changethread: Device 'Zap/26' changed to state '2' (In use) but we don't care because they're not a member of any queue. Nov 9 13:04:06 DEBUG[15577]: 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> 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:InUse 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> -- Channel 0/26, span 1 got hangup request Nov 9 13:04:13 DEBUG[15577]: channel.c:3377 ast_generic_bridge: Didn't get a frame from channel: Zap/26-1 Nov 9 13:04:13 DEBUG[15577]: channel.c:3662 ast_channel_bridge: Bridge stops bridging channels Zap/26-1 and SIP/laboratorio-2002-083cbc28 Nov 9 13:04:13 DEBUG[15577]: channel.c:1373 ast_hangup: Hanging up channel 'SIP/laboratorio-2002-083cbc28' Nov 9 13:04:13 DEBUG[15577]: chan_sip.c:2427 sip_hangup: Hangup call SIP/laboratorio-2002-083cbc28, SIP callid 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx) Nov 9 13:04:13 DEBUG[15577]: chan_sip.c:2435 sip_hangup: update_call_counter(laboratorio-2002) - decrement call limit counter Nov 9 13:04:13 DEBUG[15577]: chan_sip.c:2217 update_call_counter: Updating call counter for outgoing call Scheduling destruction of call '6d5297e95ce1691f7fcba7797208f979@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=z9hG4bK51d8a798;rport From: "5537372321" ;tag=as689a314f To: ;tag=000bbe404a2f18067675fb27-46753a9d Contact: Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Nov 9 13:04:13 DEBUG[15577]: chan_sip.c:1304 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #48 Nov 9 13:04:13 DEBUG[15577]: app_dial.c:1635 dial_exec_full: Exiting with DIALSTATUS=ANSWER. Nov 9 13:04:13 DEBUG[15577]: pbx.c:2316 __ast_pbx_run: Spawn extension (laboratorio,2002,7) exited non-zero on 'Zap/26-1' == Spawn extension (laboratorio, 2002, 7) exited non-zero on 'Zap/26-1' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '5537372321' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '5537372321' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2002' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'laboratorio' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Zap/26-1' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/laboratorio-2002-083cbc28' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Dial' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/laboratorio-2002&SIP/laboratorio-2002s|20|r' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-11-09 13:03:57' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-11-09 13:04:06' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-11-09 13:04:13' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '16' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '7' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'laboratorio-in' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1163099037.4' Nov 9 13:04:13 DEBUG[15577]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' Nov 9 13:04:13 DEBUG[15517]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:04:13 DEBUG[15517]: devicestate.c:187 do_state_change: Changing state for SIP/laboratorio-2002 - state 1 (Not in use) Nov 9 13:04:13 DEBUG[15517]: chan_sip.c:11767 sip_devicestate: Checking device state for peer laboratorio-2002 Nov 9 13:04:13 DEBUG[15577]: cdr_addon_mysql.c:206 mysql_log: cdr_mysql: inserting a CDR record. Nov 9 13:04:13 DEBUG[15577]: 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:03:57','5537372321','5537372321','2002','laboratorio', 'Zap/26-1','SIP/laboratorio-2002-083cbc28','Dial','SIP/laboratorio-2002&SIP/laboratorio-2002s|20|r',16,7,'ANSWERED',3,'laboratorio-in','') Nov 9 13:04:13 DEBUG[15577]: channel.c:1373 ast_hangup: Hanging up channel 'Zap/26-1' Nov 9 13:04:13 DEBUG[15577]: chan_zap.c:2309 zt_hangup: zt_hangup(Zap/26-1) Nov 9 13:04:13 DEBUG[15577]: chan_zap.c:2861 zt_setoption: Set option AUDIO MODE, value: ON(1) on Zap/26-1 Nov 9 13:04:13 DEBUG[15577]: chan_zap.c:2342 zt_hangup: Hangup: channel: 26 index = 0, normal = 40, callwait = -1, thirdcall = -1 Nov 9 13:04:13 DEBUG[15577]: chan_zap.c:2491 zt_hangup: Not yet hungup... Calling hangup once with icause, and clearing call Nov 9 13:04:13 DEBUG[15577]: chan_zap.c:1435 zt_disable_ec: disabled echo cancellation on channel 26 Nov 9 13:04:13 DEBUG[15577]: chan_zap.c:2782 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/26-1 Nov 9 13:04:13 DEBUG[15577]: chan_zap.c:1372 update_conf: Updated conferencing on 26, with 0 conference users Nov 9 13:04:13 DEBUG[15577]: chan_zap.c:2857 zt_setoption: Set option AUDIO MODE, value: OFF(0) on Zap/26-1 Nov 9 13:04:13 DEBUG[15577]: chan_zap.c:1435 zt_disable_ec: disabled echo cancellation on channel 26 -- Hungup 'Zap/26-1' Nov 9 13:04:13 DEBUG[15517]: devicestate.c:187 do_state_change: Changing state for Zap/26 - state 0 (Unknown) Nov 9 13:04:13 DEBUG[15583]: 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:04:13 DEBUG[15584]: app_queue.c:500 changethread: Device 'Zap/26' 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=z9hG4bK51d8a798;rport From: "5537372321" ;tag=as689a314f To: ;tag=000bbe404a2f18067675fb27-46753a9d Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx Date: Thu, 09 Nov 2006 19:04:15 GMT CSeq: 103 BYE Server: Cisco-CP7940G/7.5 Content-Length: 0 Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 0: SIP/2.0 200 OK (14) Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 1: Via: SIP/2.0/UDP 201.148.150.58:5060;branch=z9hG4bK51d8a798;rport (65) Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 2: From: "5537372321" ;tag=as689a314f (66) Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 3: To: ;tag=000bbe404a2f18067675fb27-46753a9d (83) Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 4: Call-ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx (57) Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 5: Date: Thu, 09 Nov 2006 19:04:15 GMT (35) Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 6: CSeq: 103 BYE (13) Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 7: Server: Cisco-CP7940G/7.5 (25) Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 8: Content-Length: 0 (17) Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:3392 parse_request: Header 9: (0) --- (9 headers 0 lines) --- Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:3216 find_call: = Found Their Call ID: 6d5297e95ce1691f7fcba7797208f979@metrored.com.mx Their Tag 000bbe404a2f18067675fb27-46753a9d Our tag: as689a314f Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:1401 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #48 Nov 9 13:04:13 DEBUG[15532]: chan_sip.c:1412 __sip_ack: Stopping retransmission on '6d5297e95ce1691f7fcba7797208f979@metrored.com.mx' of Request 103: Match Found Destroying call '6d5297e95ce1691f7fcba7797208f979@metrored.com.mx' atk*CLI> atk*CLI> exit [Nov 9 13:04:16] Executing last minute cleanups [Nov 9 13:04:16] Asterisk cleanly ending (0). Asterisk ending (0).