Asterisk 1.2.16, Copyright (C) 1999 - 2006 Digium, Inc. and others. Created by Mark Spencer Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details. This is free software, with components licensed under the GNU General Public License version 2 and other licenses; you are welcome to redistribute it under certain conditions. Type 'show license' for details. ========================================================================= Connected to Asterisk 1.2.16 currently running on LINUX (pid = 22499) LINUX*CLI> Verbosity is at least 4 Core debug is at least 4 [LINUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: manager.c:1250 process_message: Manager received command 'login' [LINUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: config.c:598 config_text_file_load: Parsing /etc/asterisk/manager.conf [LINUX*CLI> [Mar 23 09:11:21] == Parsing '/etc/asterisk/manager.conf': [Mar 23 09:11:21] Found [LINUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:199 ast_append_ha: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer [LINUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:199 ast_append_ha: 127.0.0.1/255.255.255.255 appended to acl for peer INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:199 ast_append_ha: *.*.*.*/255.255.255.0/255.255.255.0 appended to acl for peer INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:199 ast_append_ha: *.*.*.*/255.255.255.0/255.255.255.0 appended to acl for peer INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:199 ast_append_ha: *.*.*.*/255.255.255.0/255.255.255.0 appended to acl for peer INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:199 ast_append_ha: *.*.*.*/255.255.255.0/255.255.255.0 appended to acl for peer INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:199 ast_append_ha: *.*.*.*/255.255.255.0/255.255.255.0 appended to acl for peer INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:199 ast_append_ha: *.*.*.*/255.255.255.0/255.255.255.0 appended to acl for peer INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:199 ast_append_ha: *.*.*.*/255.255.255.0/255.255.255.0 appended to acl for peer INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:211 ast_apply_ha: ##### Testing *.*.*.* with 0.0.0.0 INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:211 ast_apply_ha: ##### Testing *.*.*.* with 127.0.0.1 INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:211 ast_apply_ha: ##### Testing *.*.*.* with 192.168.2.0 INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:211 ast_apply_ha: ##### Testing *.*.*.* with 210.17.18.0 INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:211 ast_apply_ha: ##### Testing *.*.*.* with 192.168.2.0 INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:211 ast_apply_ha: ##### Testing *.*.*.* with 210.17.18.0 INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:211 ast_apply_ha: ##### Testing *.*.*.* with 192.168.1.0 INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:211 ast_apply_ha: ##### Testing *.*.*.* with 203.160.245.0 INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:211 ast_apply_ha: ##### Testing *.*.*.* with 192.168.1.0 INUX*CLI> [Mar 23 09:11:21] == Manager '*' logged on from *.*.*.* INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: manager.c:1250 process_message: Manager received command 'Originate' INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3191 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:1889 create_addr_from_peer: Setting NAT on RTP to 0 INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: acl.c:211 ast_apply_ha: ##### Testing 192.168.1.130 with 192.168.1.0 INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:2083 sip_call: Outgoing Call for 9991234567890123 INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:2228 update_call_counter: Updating call counter for outgoing call INUX*CLI> [Mar 23 09:11:21] We're at 192.168.1.134 port 6084 INUX*CLI> [Mar 23 09:11:21] Adding codec 0x8 (alaw) to SDP INUX*CLI> [Mar 23 09:11:21] Adding non-codec 0x1 (telephone-event) to SDP INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 0: INVITE sip:9991234567890123@192.168.1.130 SIP/2.0 (49) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK3f94ad22;rport (64) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 2: From: "11011111111" ;tag=as76de44cb (66) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 3: To: (40) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 4: Contact: (40) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 5: Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 (55) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 6: CSeq: 102 INVITE (16) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 7: User-Agent: FreePP (18) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 8: Max-Forwards: 70 (16) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 9: Date: Fri, 23 Mar 2007 01:11:21 GMT (35) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 11: Content-Type: application/sdp (29) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 12: Content-Length: 217 (19) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3442 parse_request: Header 13: (0) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3474 parse_request: Line: v=0 (3) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3474 parse_request: Line: o=root 22499 22499 IN IP4 192.168.1.134 (39) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3474 parse_request: Line: s=session (9) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3474 parse_request: Line: c=IN IP4 192.168.1.134 (22) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3474 parse_request: Line: t=0 0 (5) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3474 parse_request: Line: m=audio 6084 RTP/AVP 8 101 (26) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3474 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3474 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3474 parse_request: Line: a=fmtp:101 0-16 (15) INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:3474 parse_request: Line: a=silenceSupp:off - - - - (25) INUX*CLI> [Mar 23 09:11:21] 13 headers, 10 lines INUX*CLI> [Mar 23 09:11:21] Reliably Transmitting (no NAT) to 192.168.1.130:5060: INVITE sip:9991234567890123@192.168.1.130 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK3f94ad22;rport From: "11011111111" ;tag=as76de44cb To: Contact: Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 CSeq: 102 INVITE User-Agent: FreePP Max-Forwards: 70 Date: Fri, 23 Mar 2007 01:11:21 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 217 v=0 o=root 22499 22499 IN IP4 192.168.1.134 s=session c=IN IP4 192.168.1.134 t=0 0 m=audio 6084 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- INUX*CLI> [Mar 23 09:11:21] DEBUG[22668]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #7 INUX*CLI> [Mar 23 09:11:21] <-- SIP read from 192.168.1.130:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK3f94ad22;rport From: "11011111111" ;tag=as76de44cb To: ;tag=2CFA3EC0-1D7C Date: Fri, 23 Mar 2007 01:00:59 GMT Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow-Events: telephone-event Content-Length: 0 [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 0: SIP/2.0 100 Trying (18) [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK3f94ad22;rport (64) [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 2: From: "11011111111" ;tag=as76de44cb (66) [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=2CFA3EC0-1D7C (58) [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 4: Date: Fri, 23 Mar 2007 01:00:59 GMT (35) [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 5: Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 (55) [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 7: CSeq: 102 INVITE (16) [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 8: Allow-Events: telephone-event (29) [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 9: Content-Length: 0 (17) [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 10: (0) [Mar 23 09:11:21] --- (10 headers 0 lines) --- [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:1459 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #7 - INVITE (got response) [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:1468 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '54374acf7cced37d5cc643430b0a9a1e@192.168.1.134' Request 102: Found [Mar 23 09:11:21] DEBUG[22519]: chan_sip.c:9711 handle_response_invite: SIP response 100 to standard invite INUX*CLI> [Mar 23 09:11:22] <-- SIP read from 192.168.1.130:5060: SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK3f94ad22;rport From: "11011111111" ;tag=as76de44cb To: ;tag=2CFA3EC0-1D7C Date: Fri, 23 Mar 2007 01:00:59 GMT Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow-Events: telephone-event Contact: Content-Disposition: session;handling=required Content-Type: application/sdp Content-Length: 182 v=0 o=CiscoSystemsSIP-GW-UserAgent 7749 4997 IN IP4 192.168.1.130 s=SIP Call c=IN IP4 192.168.1.130 t=0 0 m=audio 18180 RTP/AVP 8 c=IN IP4 192.168.1.130 a=rtpmap:8 PCMA/8000 [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK3f94ad22;rport (64) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 2: From: "11011111111" ;tag=as76de44cb (66) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=2CFA3EC0-1D7C (58) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 4: Date: Fri, 23 Mar 2007 01:00:59 GMT (35) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 5: Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 (55) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 7: CSeq: 102 INVITE (16) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 8: Allow-Events: telephone-event (29) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 9: Contact: (50) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 10: Content-Disposition: session;handling=required (46) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 11: Content-Type: application/sdp (29) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 12: Content-Length: 182 (19) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 13: (0) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: v=0 (3) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 7749 4997 IN IP4 192.168.1.130 (61) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: s=SIP Call (10) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: c=IN IP4 192.168.1.130 (22) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: t=0 0 (5) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: m=audio 18180 RTP/AVP 8 (23) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: c=IN IP4 192.168.1.130 (22) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) INUX*CLI> [Mar 23 09:11:22] --- (13 headers 8 lines) --- [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:1468 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '54374acf7cced37d5cc643430b0a9a1e@192.168.1.134' Request 102: Found [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:9711 handle_response_invite: SIP response 183 to standard invite [Mar 23 09:11:22] Found RTP audio format 8 [Mar 23 09:11:22] Peer audio RTP is at port 192.168.1.130:18180 [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3683 process_sdp: Peer audio RTP is at port 192.168.1.130:18180 [Mar 23 09:11:22] Found description format PCMA [Mar 23 09:11:22] Capabilities: us - 0x8 (alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) [Mar 23 09:11:22] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) INUX*CLI> [Mar 23 09:11:22] <-- SIP read from 192.168.1.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK3f94ad22;rport From: "11011111111" ;tag=as76de44cb To: ;tag=2CFA3EC0-1D7C Date: Fri, 23 Mar 2007 01:00:59 GMT Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO Allow-Events: telephone-event Contact: Content-Type: application/sdp Content-Length: 182 v=0 o=CiscoSystemsSIP-GW-UserAgent 7749 4997 IN IP4 192.168.1.130 s=SIP Call c=IN IP4 192.168.1.130 t=0 0 m=audio 18180 RTP/AVP 8 c=IN IP4 192.168.1.130 a=rtpmap:8 PCMA/8000 [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK3f94ad22;rport (64) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 2: From: "11011111111" ;tag=as76de44cb (66) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=2CFA3EC0-1D7C (58) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 4: Date: Fri, 23 Mar 2007 01:00:59 GMT (35) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 5: Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 (55) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 7: CSeq: 102 INVITE (16) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO (86) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 9: Allow-Events: telephone-event (29) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 10: Contact: (50) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 11: Content-Type: application/sdp (29) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 12: Content-Length: 182 (19) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 13: (0) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: v=0 (3) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 7749 4997 IN IP4 192.168.1.130 (61) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: s=SIP Call (10) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: c=IN IP4 192.168.1.130 (22) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: t=0 0 (5) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: m=audio 18180 RTP/AVP 8 (23) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: c=IN IP4 192.168.1.130 (22) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3474 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 23 09:11:22] --- (13 headers 8 lines) --- [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:1392 __sip_ack: Acked pending invite 102 [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '54374acf7cced37d5cc643430b0a9a1e@192.168.1.134' of Request 102: Match Found [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:9711 handle_response_invite: SIP response 200 to standard invite [Mar 23 09:11:22] Found RTP audio format 8 [Mar 23 09:11:22] Peer audio RTP is at port 192.168.1.130:18180 [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:3683 process_sdp: Peer audio RTP is at port 192.168.1.130:18180 [Mar 23 09:11:22] Found description format PCMA [Mar 23 09:11:22] Capabilities: us - 0x8 (alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) INUX*CLI> [Mar 23 09:11:22] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Mar 23 09:11:22] DEBUG[22519]: chan_sip.c:6258 build_route: build_route: Contact hop: [Mar 23 09:11:22] list_route: hop: [Mar 23 09:11:22] set_destination: Parsing for address/port to send to [Mar 23 09:11:22] set_destination: set destination to 192.168.1.130, port 5060 [Mar 23 09:11:22] Transmitting (no NAT) to 192.168.1.130:5060: ACK sip:9991234567890123@192.168.1.130:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK7378b7a1;rport From: "11011111111" ;tag=as76de44cb To: ;tag=2CFA3EC0-1D7C Contact: Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 CSeq: 102 ACK User-Agent: FreePP Max-Forwards: 70 Content-Length: 0 --- INUX*CLI> [Mar 23 09:11:22] > Channel SIP/sip-gw-00852e10 was answered. [Mar 23 09:11:22] DEBUG[22505]: chan_sip.c:11844 sip_devicestate: Checking device state for peer sip-gw [Mar 23 09:11:22] DEBUG[22505]: devicestate.c:187 do_state_change: Changing state for SIP/sip-gw - state 2 (In use) INUX*CLI> [Mar 23 09:11:22] DEBUG[22669]: pbx.c:1697 pbx_extension_helper: Launching 'Answer' INUX*CLI> [Mar 23 09:11:22] -- Executing Answer("SIP/sip-gw-00852e10", "") in new stack INUX*CLI> [Mar 23 09:11:22] DEBUG[22669]: pbx.c:1697 pbx_extension_helper: Launching 'BackGround' INUX*CLI> [Mar 23 09:11:22] DEBUG[22668]: manager.c:1250 process_message: Manager received command 'Logoff' [Mar 23 09:11:22] == Manager '*' logged off from * INUX*CLI> [Mar 23 09:11:22] -- Executing BackGround("SIP/sip-gw-00852e10", "demo-congrats") in new stack INUX*CLI> [Mar 23 09:11:22] DEBUG[22669]: channel.c:2414 set_format: Set channel SIP/sip-gw-00852e10 to write format gsm INUX*CLI> [Mar 23 09:11:22] DEBUG[22669]: rtp.c:1361 ast_rtp_write: Ooh, format changed from unknown to alaw INUX*CLI> [Mar 23 09:11:22] DEBUG[22669]: channel.c:1759 ast_settimeout: Scheduling timer at 160 sample intervals INUX*CLI> [Mar 23 09:11:22] -- Playing 'demo-congrats' (language 'en') INUX*CLI> [Mar 23 09:11:23] DEBUG[22669]: rtp.c:411 ast_rtcp_read: Got RTCP report of 132 bytes INUX*CLI> [Mar 23 09:11:25] DEBUG[22669]: rtp.c:411 ast_rtcp_read: Got RTCP report of 132 bytes INUX*CLI> [Mar 23 09:11:30] DEBUG[22669]: rtp.c:411 ast_rtcp_read: Got RTCP report of 132 bytes INUX*CLI> [Mar 23 09:11:35] DEBUG[22669]: rtp.c:411 ast_rtcp_read: Got RTCP report of 132 bytes INUX*CLI> [Mar 23 09:11:42] DEBUG[22669]: rtp.c:411 ast_rtcp_read: Got RTCP report of 112 bytes INUX*CLI> [Mar 23 09:11:46] DEBUG[22669]: rtp.c:411 ast_rtcp_read: Got RTCP report of 112 bytes INUX*CLI> [Mar 23 09:11:49] DEBUG[22669]: channel.c:1759 ast_settimeout: Scheduling timer at 0 sample intervals [Mar 23 09:11:49] DEBUG[22669]: channel.c:1759 ast_settimeout: Scheduling timer at 0 sample intervals [Mar 23 09:11:49] DEBUG[22669]: channel.c:2414 set_format: Set channel SIP/sip-gw-00852e10 to write format alaw [Mar 23 09:11:49] DEBUG[22669]: pbx.c:1697 pbx_extension_helper: Launching 'Festival' [Mar 23 09:11:49] -- Executing Festival("SIP/sip-gw-00852e10", "asterisk") in new stack [Mar 23 09:11:49] DEBUG[22669]: config.c:598 config_text_file_load: Parsing /etc/asterisk/festival.conf [Mar 23 09:11:49] == Parsing '/etc/asterisk/festival.conf': [Mar 23 09:11:49] Found [Mar 23 09:11:49] DEBUG[22669]: app_festival.c:363 festival_exec: Text passed to festival server : asterisk [Mar 23 09:11:49] DEBUG[22669]: app_festival.c:447 festival_exec: Passing text to festival... [Mar 23 09:11:49] DEBUG[22669]: app_festival.c:466 festival_exec: Passing data to channel... INUX*CLI> [Mar 23 09:11:49] DEBUG[22669]: app_festival.c:491 festival_exec: Festival WV command INUX*CLI> [Mar 23 09:11:49] DEBUG[22669]: channel.c:2414 set_format: Set channel SIP/sip-gw-00852e10 to write format slin INUX*CLI> [Mar 23 09:11:50] DEBUG[22669]: pbx.c:2336 __ast_pbx_run: Spawn extension (test,1040,3) exited non-zero on 'SIP/sip-gw-00852e10' [Mar 23 09:11:50] == Spawn extension (test, 1040, 3) exited non-zero on 'SIP/sip-gw-00852e10' INUX*CLI> [Mar 23 09:11:50] DEBUG[22669]: cdr_addon_mysql.c:206 mysql_log: cdr_mysql: inserting a CDR record. [Mar 23 09:11:50] DEBUG[22669]: cdr_addon_mysql.c:222 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr134 (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES ('2007-03-23 09:11:22','11011111111','11011111111','1040','test', 'SIP/sip-gw-00852e10','','Festival','asterisk',28,28,'ANSWERED',3,'') INUX*CLI> [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '11011111111' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '11011111111' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '1040' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'test' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'SIP/sip-gw-00852e10' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '(null)' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'Festival' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'asterisk' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '2007-03-23 09:11:22' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '2007-03-23 09:11:22' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '2007-03-23 09:11:50' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '28' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '28' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '(null)' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '1174612281.2' [Mar 23 09:11:50] DEBUG[22669]: pbx.c:1542 pbx_substitute_variables_helper_full: Function result is '(null)' INUX*CLI> [Mar 23 09:11:50] DEBUG[22669]: channel.c:1371 ast_hangup: Hanging up channel 'SIP/sip-gw-00852e10' [Mar 23 09:11:50] DEBUG[22669]: chan_sip.c:2440 sip_hangup: Hangup call SIP/sip-gw-00852e10, SIP callid 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134) [Mar 23 09:11:50] DEBUG[22669]: chan_sip.c:2448 sip_hangup: update_call_counter(9991234567890123) - decrement call limit counter [Mar 23 09:11:50] DEBUG[22669]: chan_sip.c:2228 update_call_counter: Updating call counter for outgoing call [Mar 23 09:11:50] Scheduling destruction of call '54374acf7cced37d5cc643430b0a9a1e@192.168.1.134' in 32000 ms [Mar 23 09:11:50] set_destination: Parsing for address/port to send to [Mar 23 09:11:50] set_destination: set destination to 192.168.1.130, port 5060 [Mar 23 09:11:50] Reliably Transmitting (no NAT) to 192.168.1.130:5060: BYE sip:9991234567890123@192.168.1.130:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK53fe615e;rport From: "11011111111" ;tag=as76de44cb To: ;tag=2CFA3EC0-1D7C Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 CSeq: 103 BYE User-Agent: FreePP Max-Forwards: 70 Content-Length: 0 --- [Mar 23 09:11:50] DEBUG[22669]: chan_sip.c:1307 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #9 [LINUX*CLI> [Mar 23 09:11:50] DEBUG[22505]: chan_sip.c:11844 sip_devicestate: Checking device state for peer sip-gw [Mar 23 09:11:50] DEBUG[22505]: devicestate.c:187 do_state_change: Changing state for SIP/sip-gw - state 1 (Not in use) [LINUX*CLI> [Mar 23 09:11:50] DEBUG[22677]: app_queue.c:500 changethread: Device 'SIP/sip-gw' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [LINUX*CLI> [Mar 23 09:11:50] <-- SIP read from 192.168.1.130:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK53fe615e;rport From: "11011111111" ;tag=as76de44cb To: ;tag=2CFA3EC0-1D7C Date: Fri, 23 Mar 2007 01:01:28 GMT Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 Server: Cisco-SIPGateway/IOS-12.x Content-Length: 0 CSeq: 103 BYE [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 0: SIP/2.0 200 OK (14) [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.1.134:5060;branch=z9hG4bK53fe615e;rport (64) [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 2: From: "11011111111" ;tag=as76de44cb (66) [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 3: To: ;tag=2CFA3EC0-1D7C (58) [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 4: Date: Fri, 23 Mar 2007 01:01:28 GMT (35) [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 5: Call-ID: 54374acf7cced37d5cc643430b0a9a1e@192.168.1.134 (55) [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 7: Content-Length: 0 (17) [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 8: CSeq: 103 BYE (13) [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:3442 parse_request: Header 9: (0) [Mar 23 09:11:50] --- (9 headers 0 lines) --- [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:1403 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #9 [Mar 23 09:11:50] DEBUG[22519]: chan_sip.c:1415 __sip_ack: Stopping retransmission on '54374acf7cced37d5cc643430b0a9a1e@192.168.1.134' of Request 103: Match Found [Mar 23 09:11:50] Destroying call '54374acf7cced37d5cc643430b0a9a1e@192.168.1.134' [LINUX*CLI>