Dec 3 16:37:11 DEBUG[24585]: pbx.c:1667 pbx_extension_helper: Launching 'Dial' -- Executing Dial("SIP/1.1.1.2-0819fa58", "SIP/1234567890@1.2.3.4|120") in new stack Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Dec 3 16:37:11 DEBUG[24585]: channel.c:2797 ast_channel_inherit_variables: Not copying variable STACK-outbound-s-2. Dec 3 16:37:11 DEBUG[24585]: channel.c:2797 ast_channel_inherit_variables: Not copying variable STACK-outbound-s-1. Dec 3 16:37:11 DEBUG[24585]: channel.c:2797 ast_channel_inherit_variables: Not copying variable STACK-default-#0011#6477225687-1. Dec 3 16:37:11 DEBUG[24585]: channel.c:2797 ast_channel_inherit_variables: Not copying variable SIPCALLID. Dec 3 16:37:11 DEBUG[24585]: channel.c:2797 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. Dec 3 16:37:11 DEBUG[24585]: channel.c:2797 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. Dec 3 16:37:11 DEBUG[24585]: channel.c:2797 ast_channel_inherit_variables: Not copying variable SIPURI. Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:2054 sip_call: Outgoing Call for 1234567890 Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:2195 update_call_counter: Updating call counter for outgoing call We're at 1.1.1.1 port 11676 Adding codec 0x100 (g729) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 0: INVITE sip:1234567890@1.2.3.4 SIP/2.0 (45) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK79aa78b7;rport (65) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 2: From: "9876543210" ;tag=as10757dc0 (65) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 3: To: (36) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 4: Contact: (40) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 5: Call-ID: 1cf26f212430afa95a0a0510437c29c1@1.1.1.1 (56) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 6: CSeq: 102 INVITE (16) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 7: User-Agent: Asterisk PBX (24) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 8: Max-Forwards: 70 (16) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 9: Date: Sat, 03 Dec 2005 15:37:11 GMT (35) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 11: Content-Type: application/sdp (29) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 12: Content-Length: 289 (19) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3317 parse_request: Header 13: (0) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: v=0 (3) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: o=root 24585 24585 IN IP4 1.1.1.1 (40) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: s=session (9) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: c=IN IP4 1.1.1.1 (23) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: t=0 0 (5) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: m=audio 11676 RTP/AVP 18 8 0 101 (32) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: a=rtpmap:18 G729/8000 (21) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: a=fmtp:18 annexb=noa=rtpmap:8 PCMA/8000 (39) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: a=fmtp:101 0-16 (15) Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:3349 parse_request: Line: a=silenceSupp:off - - - - (25) 13 headers, 12 lines Reliably Transmitting (no NAT) to 1.2.3.4:5060: INVITE sip:1234567890@1.2.3.4 SIP/2.0 Via: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK79aa78b7;rport From: "9876543210" ;tag=as10757dc0 To: Contact: Call-ID: 1cf26f212430afa95a0a0510437c29c1@1.1.1.1 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Sat, 03 Dec 2005 15:37:11 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 289 v=0 o=root 24585 24585 IN IP4 1.1.1.1 s=session c=IN IP4 1.1.1.1 t=0 0 m=audio 11676 RTP/AVP 18 8 0 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=noa=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Dec 3 16:37:11 DEBUG[24585]: chan_sip.c:1284 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #24 -- Called 1234567890@1.2.3.4 Dec 3 16:37:11 DEBUG[24585]: channel.c:2335 set_format: Set channel SIP/1.2.3.4-8fee to read format g729 Dec 3 16:37:11 DEBUG[24585]: channel.c:2335 set_format: Set channel SIP/1.1.1.2-0819fa58 to write format g729 Dec 3 16:37:11 DEBUG[24585]: channel.c:2335 set_format: Set channel SIP/1.1.1.2-0819fa58 to read format g729 Dec 3 16:37:11 DEBUG[24585]: channel.c:2335 set_format: Set channel SIP/1.2.3.4-8fee to write format g729 sipbe1*CLI> <-- SIP read from 1.2.3.4:5060: SIP/2.0 100 Trying CSeq: 102 INVITE Via: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK79aa78b7;rport From: "9876543210" ;tag=as10757dc0 Call-ID: 1cf26f212430afa95a0a0510437c29c1@1.1.1.1 To: ;tag=0312230519347309 Contact: Content-Length: 0 Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 0: SIP/2.0 100 Trying (18) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 1: CSeq: 102 INVITE (16) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 2: Via: SIP/2.0/UDP 1.1.1.1:5060;branch=z9hG4bK79aa78b7;rport (65) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 3: From: "9876543210" ;tag=as10757dc0 (65) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 4: Call-ID: 1cf26f212430afa95a0a0510437c29c1@1.1.1.1 (56) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 5: To: ;tag=0312230519347309 (57) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 6: Contact: (59) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 7: Content-Length: 0 (17) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:1433 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #24 - INVITE (got response) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:1442 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '1cf26f212430afa95a0a0510437c29c1@1.1.1.1' Request 102: Found Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:9426 handle_response_invite: SIP response 100 to standard invite sipbe1*CLI> <-- SIP read from 1.2.3.4:5060: BYE sip:9876543210@1.1.1.1 SIP/2.0 CSeq: 1 BYE Via: SIP/2.0/UDP 1.2.3.4:5060 From: ;tag=0312230519347309 Call-ID: 1cf26f212430afa95a0a0510437c29c1@1.1.1.1 To: "9876543210" ;tag=as10757dc0 Contact: Content-Length: 0 Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 0: BYE sip:9876543210@1.1.1.1 SIP/2.0 (41) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 1: CSeq: 1 BYE (11) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 2: Via: SIP/2.0/UDP 1.2.3.4:5060 (36) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 3: From: ;tag=0312230519347309 (59) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 4: Call-ID: 1cf26f212430afa95a0a0510437c29c1@1.1.1.1 (56) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 5: To: "9876543210" ;tag=as10757dc0 (63) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 6: Contact: (59) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 7: Content-Length: 0 (17) Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:3317 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Dec 3 16:37:12 DEBUG[24265]: chan_sip.c:10909 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 1.2.3.4 : 5060 (non-NAT) Transmitting (no NAT) to 1.2.3.4:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 1.2.3.4:5060;received=1.2.3.4 From: ;tag=0312230519347309 To: "9876543210" ;tag=as10757dc0 Call-ID: 1cf26f212430afa95a0a0510437c29c1@1.1.1.1 CSeq: 1 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- Dec 3 16:37:12 DEBUG[24585]: channel.c:1312 ast_hangup: Hanging up channel 'SIP/1.2.3.4-8fee' Dec 3 16:37:12 DEBUG[24585]: chan_sip.c:2401 sip_hangup: Hangup call SIP/1.2.3.4-8fee, SIP callid 1cf26f212430afa95a0a0510437c29c1@1.1.1.1) Dec 3 16:37:12 DEBUG[24585]: chan_sip.c:2409 sip_hangup: update_call_counter(1234567890) - decrement call limit counter Dec 3 16:37:12 DEBUG[24585]: chan_sip.c:2195 update_call_counter: Updating call counter for outgoing call Dec 3 16:37:12 DEBUG[24261]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 1.2.3.4 Dec 3 16:37:12 DEBUG[24261]: devicestate.c:187 do_state_change: Changing state for SIP/1.2.3.4 - state 1 (Not in use) == No one is available to answer at this time (1:0/0/0) Dec 3 16:37:12 DEBUG[24585]: app_dial.c:1587 dial_exec_full: Exiting with DIALSTATUS=NOANSWER.