centrala*CLI> centrala*CLI> set debug 4 centrala*CLI> set verbose 4 Core debug is at least 4 Verbosity is at least 4 centrala*CLI> sip debug SIP Debugging re-enabled centrala*CLI> <--- SIP read from 10.10.119.248:5060 ---> INVITE sip:8367@10.10.119.251 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-75b93de6 From: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 To: Remote-Party-ID: 9971 ;screen=yes;party=calling Call-ID: 94ebae26-3857881e@10.10.119.248 CSeq: 101 INVITE Max-Forwards: 70 Contact: 9971 Expires: 240 User-Agent: Linksys/SPA9000-3.2.8(d) Allow-Events: talk, hold, conference Content-Length: 397 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 105867 105867 IN IP4 192.168.0.1 s=- c=IN IP4 10.10.119.248 t=0 0 m=audio 16394 RTP/AVP 18 0 2 4 8 96 97 98 101 a=rtpmap:18 G729a/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:96 G726-40/8000 a=rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv <-------------> [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: INVITE sip:8367@10.10.119.251 SIP/2.0 (45) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-75b93de6 (61) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 (79) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: (36) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Remote-Party-ID: 9971 ;screen=yes;party=calling (83) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 94ebae26-3857881e@10.10.119.248 (42) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: CSeq: 101 INVITE (16) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: Max-Forwards: 70 (16) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Contact: 9971 (55) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Expires: 240 (12) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: User-Agent: Linksys/SPA9000-3.2.8(d) (36) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 11: Allow-Events: talk, hold, conference (36) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 12: Content-Length: 397 (19) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 13: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 14: Supported: x-sipura (19) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 15: Content-Type: application/sdp (29) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 16: (0) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: o=- 105867 105867 IN IP4 192.168.0.1 (36) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: s=- (3) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.248 (24) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: m=audio 16394 RTP/AVP 18 0 2 4 8 96 97 98 101 (45) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:18 G729a/8000 (22) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:2 G726-32/8000 (23) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:96 G726-40/8000 (24) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:97 G726-24/8000 (24) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:98 G726-16/8000 (24) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=fmtp:101 0-15 (15) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=ptime:30 (10) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=sendrecv (10) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: (0) --- (16 headers 19 lines) --- [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:2530 do_setnat: Setting NAT on RTP to Off [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:2540 do_setnat: Setting NAT on UDPTL to Off [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4217 sip_alloc: Allocating new SIP dialog for 94ebae26-3857881e@10.10.119.248 - INVITE (With RTP) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:14286 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:1639 parse_sip_options: Begin: parsing SIP "Supported: x-sipura" [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:1647 parse_sip_options: Found SIP option: -x-sipura- [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:1659 parse_sip_options: Found private SIP option, not supported: x-sipura Sending to 10.10.119.248 : 5060 (no NAT) Using INVITE request as basis request - 94ebae26-3857881e@10.10.119.248 [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:2530 do_setnat: Setting NAT on RTP to Off [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:2540 do_setnat: Setting NAT on UDPTL to Off Found user '9971' Found RTP audio format 18 Found RTP audio format 0 Found RTP audio format 2 Found RTP audio format 4 Found RTP audio format 8 Found RTP audio format 96 Found RTP audio format 97 Found RTP audio format 98 Found RTP audio format 101 Peer audio RTP is at port 10.10.119.248:16394 [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4791 process_sdp: Peer doesn't provide T.38 UDPTL Found description format G729a for ID 18 Found description format PCMU for ID 0 Found description format G726-32 for ID 2 Found description format G723 for ID 4 Found description format PCMA for ID 8 Found description format G726-40 for ID 96 Found description format G726-24 for ID 97 Found description format G726-16 for ID 98 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Got unsupported a:ptime in SDP offer [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:5003 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x8 (alaw), peer - audio=0xd0d (g723|ulaw|alaw|g726|g729|ilbc)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.10.119.248:16394 [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:5080 process_sdp: We're settling with these formats: 0x8 (alaw) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:13078 handle_request_invite: Checking SIP call limits for device 9971 [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:2946 update_call_counter: Updating call counter for incoming call Looking for 8367 in default (domain 10.10.119.251) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:3724 sip_new: *** Our native formats are 0x8 (alaw) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:3725 sip_new: *** Joint capabilities are 0x8 (alaw) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:3726 sip_new: *** Our capabilities are 0x8 (alaw) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:3727 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:3750 sip_new: This channel will not be able to handle video. [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:7816 build_route: build_route: Contact hop: 9971 list_route: hop: [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:13152 handle_request_invite: SIP/9971-081b1ee0: New call is still down.... Trying... <--- Transmitting (no NAT) to 10.10.119.248:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-75b93de6;received=10.10.119.248 From: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 To: Call-ID: 94ebae26-3857881e@10.10.119.248 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Nov 10 19:16:02] DEBUG[8966]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9971-081b1ee0 [Nov 10 19:16:02] DEBUG[8947]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9971 [Nov 10 19:16:02] DEBUG[8947]: chan_sip.c:14872 sip_devicestate: Checking device state for peer 9971 [Nov 10 19:16:02] DEBUG[8947]: devicestate.c:287 do_state_change: Changing state for SIP/9971 - state 1 (Not in use) [Nov 10 19:16:02] DEBUG[9063]: pbx.c:1767 pbx_extension_helper: Launching 'Dial' -- Executing [8367@default:1] Dial("SIP/9971-081b1ee0", "SIP/10.10.119.225/8367|60|r") in new stack [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:14930 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4217 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Nov 10 19:16:02] DEBUG[9064]: app_queue.c:546 changethread: Device 'SIP/9971' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:3724 sip_new: *** Our native formats are 0x8 (alaw) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:3725 sip_new: *** Joint capabilities are 0x0 (nothing) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:3726 sip_new: *** Our capabilities are 0x8 (alaw) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:3727 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:3729 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:3750 sip_new: This channel will not be able to handle video. [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:16508 sip_set_rtp_peer: Early remote bridge setting SIP '5740ebc11cc18005748a10d022fd1342@10.10.119.251' - Sending media to 10.10.119.248 [Nov 10 19:16:02] DEBUG[9063]: rtp.c:1520 ast_rtp_make_compatible: Seeded SDP of 'SIP/10.10.119.225-081c4b10' with that of 'SIP/9971-081b1ee0' [Nov 10 19:16:02] DEBUG[9063]: channel.c:3185 ast_channel_inherit_variables: Not copying variable STACK-default-8367-1. [Nov 10 19:16:02] DEBUG[9063]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Nov 10 19:16:02] DEBUG[9063]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Nov 10 19:16:02] DEBUG[9063]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Nov 10 19:16:02] DEBUG[9063]: channel.c:3185 ast_channel_inherit_variables: Not copying variable SIPURI. [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:2781 sip_call: Outgoing Call for 8367 [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:2946 update_call_counter: Updating call counter for outgoing call [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:2795 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:6053 add_sdp: ** Our capability: 0x8 (alaw) Video flag: False [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:6054 add_sdp: ** Our prefcodec: 0x8 (alaw) Audio is at 10.10.119.251 port 11100 Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:6185 add_sdp: -- Done with adding codecs to SDP [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:6230 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 0: INVITE sip:8367@10.10.119.225 SIP/2.0 (45) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK452eb70b;rport (66) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 2: From: "9971" ;tag=as4d4a0895 (64) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 3: To: (36) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 4: Contact: (40) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 6: CSeq: 102 INVITE (16) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 8: Max-Forwards: 70 (16) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 9: Date: Fri, 10 Nov 2006 18:16:02 GMT (35) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 11: Supported: replaces (19) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 12: Content-Type: application/sdp (29) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 13: Content-Length: 244 (19) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 14: (0) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: o=root 9063 9063 IN IP4 10.10.119.248 (39) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: s=session (9) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.248 (24) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: m=audio 16394 RTP/AVP 8 101 (27) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: a=fmtp:101 0-16 (15) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: a=silenceSupp:off - - - - (25) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: a=ptime:20 (10) [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 10.10.119.225:5060: INVITE sip:8367@10.10.119.225 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK452eb70b;rport From: "9971" ;tag=as4d4a0895 To: Contact: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Fri, 10 Nov 2006 18:16:02 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 244 v=0 o=root 9063 9063 IN IP4 10.10.119.248 s=session c=IN IP4 10.10.119.248 t=0 0 m=audio 16394 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Nov 10 19:16:02] DEBUG[9063]: chan_sip.c:1931 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #35 -- Called 10.10.119.225/8367 <--- Transmitting (no NAT) to 10.10.119.248:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-75b93de6;received=10.10.119.248 From: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 To: ;tag=as2c191251 Call-ID: 94ebae26-3857881e@10.10.119.248 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK452eb70b;rport From: "9971" ;tag=as4d4a0895 To: ;tag=6F0A037C-A94 Date: Fri, 10 Nov 2006 12:20:19 GMT Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow-Events: telephone-event Content-Length: 0 <-------------> [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 100 Trying (18) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK452eb70b;rport (66) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: "9971" ;tag=as4d4a0895 (64) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=6F0A037C-A94 (53) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Date: Fri, 10 Nov 2006 12:20:19 GMT (35) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: CSeq: 102 INVITE (16) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Allow-Events: telephone-event (29) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Content-Length: 0 (17) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:2076 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #35 - INVITE (got response) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:2085 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '5740ebc11cc18005748a10d022fd1342@10.10.119.251' Request 102: Found [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:11408 handle_response_invite: SIP response 100 to standard invite centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK452eb70b;rport From: "9971" ;tag=as4d4a0895 To: ;tag=6F0A037C-A94 Date: Fri, 10 Nov 2006 12:20:19 GMT Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Contact: Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 197 v=0 o=CiscoSystemsSIP-GW-UserAgent 268 88 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 16578 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK452eb70b;rport (66) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: "9971" ;tag=as4d4a0895 (64) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=6F0A037C-A94 (53) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Date: Fri, 10 Nov 2006 12:20:19 GMT (35) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: CSeq: 102 INVITE (16) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Allow-Events: telephone-event (29) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: Contact: (46) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 11: Content-Type: application/sdp (29) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 13: Content-Length: 197 (19) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 14: (0) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 268 88 IN IP4 10.10.119.225 (60) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: s=SIP Call (10) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: m=audio 16578 RTP/AVP 8 (23) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=ptime:20 (10) --- (14 headers 9 lines) --- [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:2085 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '5740ebc11cc18005748a10d022fd1342@10.10.119.251' Request 102: Found [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:11408 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 8 Peer audio RTP is at port 10.10.119.225:16578 [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4791 process_sdp: Peer doesn't provide T.38 UDPTL Found description format PCMA for ID 8 Got unsupported a:ptime in SDP offer [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:5003 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081c4b10 Capabilities: us - 0x8 (alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.119.225:16578 [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:5080 process_sdp: We're settling with these formats: 0x8 (alaw) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:5087 process_sdp: We have an owner, now see if we need to change this call -- SIP/10.10.119.225-081c4b10 is making progress passing it to SIP/9971-081b1ee0 centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK452eb70b;rport From: "9971" ;tag=as4d4a0895 To: ;tag=6F0A037C-A94 Date: Fri, 10 Nov 2006 12:20:19 GMT Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Contact: Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 197 v=0 o=CiscoSystemsSIP-GW-UserAgent 268 88 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 16578 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 183 Session Progress (28) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK452eb70b;rport (66) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: "9971" ;tag=as4d4a0895 (64) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=6F0A037C-A94 (53) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Date: Fri, 10 Nov 2006 12:20:19 GMT (35) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: CSeq: 102 INVITE (16) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Allow-Events: telephone-event (29) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: Contact: (46) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 11: Content-Type: application/sdp (29) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 13: Content-Length: 197 (19) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 14: (0) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 268 88 IN IP4 10.10.119.225 (60) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: s=SIP Call (10) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: m=audio 16578 RTP/AVP 8 (23) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=ptime:20 (10) --- (14 headers 9 lines) --- [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:2085 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '5740ebc11cc18005748a10d022fd1342@10.10.119.251' Request 102: Found [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:11408 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 8 Peer audio RTP is at port 10.10.119.225:16578 [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:4791 process_sdp: Peer doesn't provide T.38 UDPTL Found description format PCMA for ID 8 Got unsupported a:ptime in SDP offer [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:5003 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081c4b10 Capabilities: us - 0x8 (alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.119.225:16578 [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:5080 process_sdp: We're settling with these formats: 0x8 (alaw) [Nov 10 19:16:02] DEBUG[8966]: chan_sip.c:5087 process_sdp: We have an owner, now see if we need to change this call -- SIP/10.10.119.225-081c4b10 is making progress passing it to SIP/9971-081b1ee0 centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK452eb70b;rport From: "9971" ;tag=as4d4a0895 To: ;tag=6F0A037C-A94 Date: Fri, 10 Nov 2006 12:20:19 GMT Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Contact: Content-Type: application/sdp Content-Disposition: session;handling=required Content-Length: 197 v=0 o=CiscoSystemsSIP-GW-UserAgent 268 88 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 16578 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 200 OK (14) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK452eb70b;rport (66) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: "9971" ;tag=as4d4a0895 (64) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=6F0A037C-A94 (53) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Date: Fri, 10 Nov 2006 12:20:19 GMT (35) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: CSeq: 102 INVITE (16) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Allow-Events: telephone-event (29) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: Contact: (46) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 11: Content-Type: application/sdp (29) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 12: Content-Disposition: session;handling=required (46) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 13: Content-Length: 197 (19) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 14: (0) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 268 88 IN IP4 10.10.119.225 (60) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: s=SIP Call (10) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: m=audio 16578 RTP/AVP 8 (23) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=ptime:20 (10) --- (14 headers 9 lines) --- [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:2025 __sip_ack: Acked pending invite 102 [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:2043 __sip_ack: Stopping retransmission on '5740ebc11cc18005748a10d022fd1342@10.10.119.251' of Request 102: Match Not Found [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:11408 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 Peer audio RTP is at port 10.10.119.225:16578 [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4791 process_sdp: Peer doesn't provide T.38 UDPTL Found description format PCMA for ID 8 Got unsupported a:ptime in SDP offer [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:5003 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081c4b10 Capabilities: us - 0x8 (alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.119.225:16578 [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:5080 process_sdp: We're settling with these formats: 0x8 (alaw) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:5087 process_sdp: We have an owner, now see if we need to change this call [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:2946 update_call_counter: Updating call counter for outgoing call [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:7816 build_route: build_route: Contact hop: list_route: hop: [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:5509 reqprep: Strict routing enforced for session 5740ebc11cc18005748a10d022fd1342@10.10.119.251 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.119.225, port 5060 Transmitting (no NAT) to 10.10.119.225:5060: ACK sip:8367@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK44680ff0;rport From: "9971" ;tag=as4d4a0895 To: ;tag=6F0A037C-A94 Contact: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Nov 10 19:16:09] DEBUG[9063]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/10.10.119.225-081c4b10 [Nov 10 19:16:09] DEBUG[8947]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 10.10.119.225 [Nov 10 19:16:09] DEBUG[8947]: chan_sip.c:14872 sip_devicestate: Checking device state for peer 10.10.119.225 [Nov 10 19:16:09] DEBUG[8947]: channel.c:943 channel_find_locked: Avoiding initial deadlock for channel '0x81d6058' -- SIP/10.10.119.225-081c4b10 answered SIP/9971-081b1ee0 [Nov 10 19:16:09] DEBUG[9063]: chan_sip.c:16508 sip_set_rtp_peer: Early remote bridge setting SIP '94ebae26-3857881e@10.10.119.248' - Sending media to 10.10.119.225 [Nov 10 19:16:09] DEBUG[9063]: rtp.c:1455 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/9971-081b1ee0' with that of 'SIP/10.10.119.225-081c4b10' [Nov 10 19:16:09] DEBUG[9063]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9971-081b1ee0 [Nov 10 19:16:09] DEBUG[9063]: chan_sip.c:3393 sip_answer: SIP answering channel: SIP/9971-081b1ee0 [Nov 10 19:16:09] DEBUG[9063]: chan_sip.c:6285 transmit_response_with_sdp: Setting framing from config on incoming call [Nov 10 19:16:09] DEBUG[9063]: chan_sip.c:6053 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Nov 10 19:16:09] DEBUG[9063]: chan_sip.c:6054 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.10.119.251 port 16946 Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Nov 10 19:16:09] DEBUG[9063]: chan_sip.c:6185 add_sdp: -- Done with adding codecs to SDP [Nov 10 19:16:09] DEBUG[9063]: chan_sip.c:6230 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) <--- Reliably Transmitting (no NAT) to 10.10.119.248:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-75b93de6;received=10.10.119.248 From: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 To: ;tag=as2c191251 Call-ID: 94ebae26-3857881e@10.10.119.248 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 244 v=0 o=root 9063 9063 IN IP4 10.10.119.225 s=session c=IN IP4 10.10.119.225 t=0 0 m=audio 16578 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Nov 10 19:16:09] DEBUG[9063]: chan_sip.c:1931 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #37 -- Native bridging SIP/9971-081b1ee0 and SIP/10.10.119.225-081c4b10 centrala*CLI> <--- SIP read from 10.10.119.248:5060 ---> ACK sip:8367@10.10.119.251 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-20813e2c From: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 To: ;tag=as2c191251 Call-ID: 94ebae26-3857881e@10.10.119.248 CSeq: 101 ACK Max-Forwards: 70 Contact: 9971 User-Agent: Linksys/SPA9000-3.2.8(d) Allow-Events: talk, hold, conference Content-Length: 0 <-------------> [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: ACK sip:8367@10.10.119.251 SIP/2.0 (42) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-20813e2c (61) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 (79) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=as2c191251 (51) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Call-ID: 94ebae26-3857881e@10.10.119.248 (42) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: CSeq: 101 ACK (13) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Max-Forwards: 70 (16) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: Contact: 9971 (55) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: User-Agent: Linksys/SPA9000-3.2.8(d) (36) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Allow-Events: talk, hold, conference (36) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: Content-Length: 0 (17) [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 11: (0) --- (11 headers 0 lines) --- [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:14286 handle_request: **** Received ACK (6) - Command in SIP ACK [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:2033 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #37 [Nov 10 19:16:09] DEBUG[8966]: chan_sip.c:2043 __sip_ack: Stopping retransmission on '94ebae26-3857881e@10.10.119.248' of Response 101: Match Not Found [Nov 10 19:16:09] DEBUG[8947]: devicestate.c:287 do_state_change: Changing state for SIP/10.10.119.225 - state 2 (In use) [Nov 10 19:16:09] DEBUG[8947]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9971 [Nov 10 19:16:09] DEBUG[8947]: chan_sip.c:14872 sip_devicestate: Checking device state for peer 9971 [Nov 10 19:16:09] DEBUG[8947]: devicestate.c:287 do_state_change: Changing state for SIP/9971 - state 1 (Not in use) [Nov 10 19:16:09] DEBUG[9065]: app_queue.c:546 changethread: Device 'SIP/10.10.119.225' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Nov 10 19:16:09] DEBUG[9066]: app_queue.c:546 changethread: Device 'SIP/9971' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. centrala*CLI> <--- SIP read from 10.10.119.225:50914 ---> INVITE sip:9971@10.10.119.251:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK10E8526F1 From: ;tag=6F0A037C-A94 To: "9971" ;tag=as4d4a0895 Date: Fri, 10 Nov 2006 12:20:32 GMT Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 Supported: 100rel,timer,resource-priority,replaces Min-SE: 1800 Cisco-Guid: 2859328702-1877742043-2740823462-4050708206 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 101 INVITE Max-Forwards: 70 Timestamp: 1163161232 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 402 v=0 o=CiscoSystemsSIP-GW-UserAgent 268 89 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=image 16578 udptl t38 c=IN IP4 10.10.119.225 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: INVITE sip:9971@10.10.119.251:5060 SIP/2.0 (49) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK10E8526F1 (61) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: ;tag=6F0A037C-A94 (55) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: "9971" ;tag=as4d4a0895 (62) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Date: Fri, 10 Nov 2006 12:20:32 GMT (35) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Supported: 100rel,timer,resource-priority,replaces (50) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: Min-SE: 1800 (13) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Cisco-Guid: 2859328702-1877742043-2740823462-4050708206 (55) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 11: CSeq: 101 INVITE (16) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 12: Max-Forwards: 70 (16) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 13: Timestamp: 1163161232 (21) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 14: Contact: (46) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 15: Expires: 180 (12) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 16: Allow-Events: telephone-event (29) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 17: Content-Type: application/sdp (29) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 18: Content-Length: 402 (19) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 19: (0) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 268 89 IN IP4 10.10.119.225 (60) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: s=SIP Call (10) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: m=image 16578 udptl t38 (23) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxVersion:0 (17) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38MaxBitRate:14400 (21) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) --- (19 headers 16 lines) --- [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:14286 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1639 parse_sip_options: Begin: parsing SIP "Supported: 100rel,timer,resource-priority,replaces" [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1647 parse_sip_options: Found SIP option: -100rel- [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1653 parse_sip_options: Matched SIP option: 100rel [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1647 parse_sip_options: Found SIP option: -timer- [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1653 parse_sip_options: Matched SIP option: timer [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1647 parse_sip_options: Found SIP option: -resource-priority- [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1653 parse_sip_options: Matched SIP option: resource-priority [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1647 parse_sip_options: Found SIP option: -replaces- [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1653 parse_sip_options: Matched SIP option: replaces Sending to 10.10.119.225 : 5060 (no NAT) Got T.38 offer in SDP in dialog 5740ebc11cc18005748a10d022fd1342@10.10.119.251 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4721 process_sdp: T38 state changed to 4 on channel SIP/10.10.119.225-081c4b10 Peer doesn't provide audio [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4787 process_sdp: Peer T.38 UDPTL is at port 10.10.119.225:16578 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4935 process_sdp: FaxVersion: 0 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4911 process_sdp: T38MaxBitRate: 14400 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4949 process_sdp: FillBitRemoval: 0 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4955 process_sdp: Transcoding MMR: 0 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4962 process_sdp: Transcoding JBIG: 0 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4968 process_sdp: RateMangement: transferredTCF [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4907 process_sdp: MaxBufferSize:200 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4943 process_sdp: FaxMaxDatagram: 72 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4976 process_sdp: UDP EC: t38UDPRedundancy [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4996 process_sdp: Our T38 capability = (3856), peer T38 capability (16160), joint T38 capability (3872) Capabilities: us - 0x8 (alaw), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:5038 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:13130 handle_request_invite: Got a SIP re-invite for call 5740ebc11cc18005748a10d022fd1342@10.10.119.251 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:13219 handle_request_invite: SIP/10.10.119.225-081c4b10: This call is UP.... [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:16360 sip_handle_t38_reinvite: Sending reinvite on SIP '94ebae26-3857881e@10.10.119.248' - It's UDPTL soon redirected to IP 10.10.119.225:16578 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:5509 reqprep: Strict routing enforced for session 94ebae26-3857881e@10.10.119.248 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.119.248, port 5060 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:5906 add_t38_sdp: T.38 UDPTL is at 10.10.119.251 port 4470 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:5912 add_t38_sdp: Our T38 capability (3856), peer T38 capability (3872), joint capability (3872) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:5839 t38_get_rate: T38MaxFaxRate 9600 found [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1587 initialize_initreq: Initializing already initialized SIP dialog 94ebae26-3857881e@10.10.119.248 (presumably reinvite) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: INVITE sip:9971@10.10.119.248:5060 SIP/2.0 (49) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK13463766;rport (66) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: ;tag=as2c191251 (53) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 (77) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Contact: (41) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 94ebae26-3857881e@10.10.119.248 (42) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: CSeq: 102 INVITE (16) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Max-Forwards: 70 (16) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: Supported: replaces (19) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 11: X-asterisk-info: SIP re-invite (T38 switchover) (47) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 12: Content-Type: application/sdp (29) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 13: Content-Length: 262 (19) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 14: (0) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: o=root 9063 9064 IN IP4 10.10.119.225 (39) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: s=session (9) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: m=image 16578 udptl t38 (23) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxVersion:0 (17) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38MaxBitRate:9600 (20) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxMaxBuffer:72 (20) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) Reliably Transmitting (no NAT) to 10.10.119.248:5060: INVITE sip:9971@10.10.119.248:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK13463766;rport From: ;tag=as2c191251 To: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 Contact: Call-ID: 94ebae26-3857881e@10.10.119.248 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-info: SIP re-invite (T38 switchover) Content-Type: application/sdp Content-Length: 262 v=0 o=root 9063 9064 IN IP4 10.10.119.225 s=session c=IN IP4 10.10.119.225 t=0 0 m=image 16578 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:72 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy --- [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1931 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #38 centrala*CLI> <--- SIP read from 10.10.119.248:5060 ---> SIP/2.0 100 Trying To: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 From: ;tag=as2c191251 Call-ID: 94ebae26-3857881e@10.10.119.248 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK13463766 Server: Linksys/SPA9000-3.2.8(d) Allow-Events: talk, hold, conference Content-Length: 0 <-------------> [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 100 Trying (18) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: To: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 (77) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: ;tag=as2c191251 (53) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: Call-ID: 94ebae26-3857881e@10.10.119.248 (42) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: CSeq: 102 INVITE (16) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK13463766 (60) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Server: Linksys/SPA9000-3.2.8(d) (32) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: Allow-Events: talk, hold, conference (36) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Content-Length: 0 (17) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:2076 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #38 - INVITE (got response) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:2085 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '94ebae26-3857881e@10.10.119.248' Request 102: Found [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:11406 handle_response_invite: SIP response 100 to RE-invite on outgoing call 94ebae26-3857881e@10.10.119.248 centrala*CLI> <--- SIP read from 10.10.119.248:5060 ---> SIP/2.0 200 OK To: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 From: ;tag=as2c191251 Call-ID: 94ebae26-3857881e@10.10.119.248 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK13463766 Contact: 9971 Server: Linksys/SPA9000-3.2.8(d) Remote-Party-ID: 9971 ;screen=yes;party=calling Allow-Events: talk, hold, conference Content-Length: 345 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 107167 107167 IN IP4 192.168.0.1 s=- c=IN IP4 10.10.119.248 t=0 0 m=image 16394 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:14400 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:200 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy <-------------> [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 200 OK (14) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: To: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 (77) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: ;tag=as2c191251 (53) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: Call-ID: 94ebae26-3857881e@10.10.119.248 (42) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: CSeq: 102 INVITE (16) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK13463766 (60) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Contact: 9971 (55) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: Server: Linksys/SPA9000-3.2.8(d) (32) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Remote-Party-ID: 9971 ;screen=yes;party=calling (83) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Allow-Events: talk, hold, conference (36) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: Content-Length: 345 (19) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 12: Supported: x-sipura (19) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 13: Content-Type: application/sdp (29) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 14: (0) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: o=- 107167 107167 IN IP4 192.168.0.1 (36) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: s=- (3) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.248 (24) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: m=image 16394 udptl t38 (23) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxVersion:0 (17) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38MaxBitRate:14400 (21) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxFillBitRemoval:0 (24) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxTranscodingMMR:0 (24) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxTranscodingJBIG:0 (25) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxRateManagement:transferredTCF (37) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxMaxBuffer:200 (21) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxMaxDatagram:72 (22) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=T38FaxUdpEC:t38UDPRedundancy (30) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: (0) --- (14 headers 16 lines) --- [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:2025 __sip_ack: Acked pending invite 102 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:2043 __sip_ack: Stopping retransmission on '94ebae26-3857881e@10.10.119.248' of Request 102: Match Not Found [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:11406 handle_response_invite: SIP response 200 to RE-invite on outgoing call 94ebae26-3857881e@10.10.119.248 Got T.38 offer in SDP in dialog 94ebae26-3857881e@10.10.119.248 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4721 process_sdp: T38 state changed to 4 on channel SIP/9971-081b1ee0 Peer doesn't provide audio [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4787 process_sdp: Peer T.38 UDPTL is at port 10.10.119.248:16394 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4935 process_sdp: FaxVersion: 0 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4911 process_sdp: T38MaxBitRate: 14400 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4949 process_sdp: FillBitRemoval: 0 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4955 process_sdp: Transcoding MMR: 0 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4962 process_sdp: Transcoding JBIG: 0 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4968 process_sdp: RateMangement: transferredTCF [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4907 process_sdp: MaxBufferSize:200 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4943 process_sdp: FaxMaxDatagram: 72 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4976 process_sdp: UDP EC: t38UDPRedundancy [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4996 process_sdp: Our T38 capability = (3856), peer T38 capability (16160), joint T38 capability (3872) Capabilities: us - 0x8 (alaw), peer - audio=0x0 (nothing)/video=0x0 (nothing), combined - 0x0 (nothing) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:5038 process_sdp: Have T.38 but no audio codecs, accepting offer anyway [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:2946 update_call_counter: Updating call counter for outgoing call [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:7816 build_route: build_route: Contact hop: 9971 list_route: hop: [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:16388 sip_handle_t38_reinvite: Responding 200 OK on SIP '5740ebc11cc18005748a10d022fd1342@10.10.119.251' - It's UDPTL soon redirected to IP 10.10.119.248:16394 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:16395 sip_handle_t38_reinvite: T38 changed state to 5 on channel SIP/9971-081b1ee0 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:16396 sip_handle_t38_reinvite: T38 changed state to 5 on channel SIP/10.10.119.225-081c4b10 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:5906 add_t38_sdp: T.38 UDPTL is at 10.10.119.251 port 4810 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:5912 add_t38_sdp: Our T38 capability (3856), peer T38 capability (3872), joint capability (3872) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:5839 t38_get_rate: T38MaxFaxRate 9600 found <--- Reliably Transmitting (no NAT) to 10.10.119.225:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK10E8526F1;received=10.10.119.225 From: ;tag=6F0A037C-A94 To: "9971" ;tag=as4d4a0895 Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 262 v=0 o=root 9063 9064 IN IP4 10.10.119.248 s=session c=IN IP4 10.10.119.248 t=0 0 m=image 16394 udptl t38 a=T38FaxVersion:0 a=T38MaxBitRate:9600 a=T38FaxFillBitRemoval:0 a=T38FaxTranscodingMMR:0 a=T38FaxTranscodingJBIG:0 a=T38FaxRateManagement:transferredTCF a=T38FaxMaxBuffer:72 a=T38FaxMaxDatagram:72 a=T38FaxUdpEC:t38UDPRedundancy <------------> [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:1931 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #39 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:5509 reqprep: Strict routing enforced for session 94ebae26-3857881e@10.10.119.248 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.119.248, port 5060 Transmitting (no NAT) to 10.10.119.248:5060: ACK sip:9971@10.10.119.248:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK225e9cd7;rport From: ;tag=as2c191251 To: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 Contact: Call-ID: 94ebae26-3857881e@10.10.119.248 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Nov 10 19:16:15] DEBUG[9063]: rtp.c:2693 bridge_native_loop: Oooh, 'SIP/10.10.119.225-081c4b10' changed end address to 0.0.0.0:0 (format 8) [Nov 10 19:16:15] DEBUG[9063]: rtp.c:2695 bridge_native_loop: Oooh, 'SIP/10.10.119.225-081c4b10' changed end vaddress to 0.0.0.0:0 (format 8) [Nov 10 19:16:15] DEBUG[9063]: rtp.c:2697 bridge_native_loop: Oooh, 'SIP/10.10.119.225-081c4b10' was 10.10.119.225:16578/(format 8) [Nov 10 19:16:15] DEBUG[9063]: rtp.c:2699 bridge_native_loop: Oooh, 'SIP/10.10.119.225-081c4b10' was 0.0.0.0:0/(format 8) [Nov 10 19:16:15] DEBUG[9063]: rtp.c:2711 bridge_native_loop: Oooh, 'SIP/9971-081b1ee0' changed end address to 0.0.0.0:0 (format 3341) [Nov 10 19:16:15] DEBUG[9063]: rtp.c:2713 bridge_native_loop: Oooh, 'SIP/9971-081b1ee0' was 10.10.119.248:16394/(format 3341) centrala*CLI> <--- SIP read from 10.10.119.225:50914 ---> ACK sip:9971@10.10.119.251:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK10E8621C2 From: ;tag=6F0A037C-A94 To: "9971" ;tag=as4d4a0895 Date: Fri, 10 Nov 2006 12:20:32 GMT Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 Max-Forwards: 70 CSeq: 101 ACK Content-Length: 0 <-------------> [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: ACK sip:9971@10.10.119.251:5060 SIP/2.0 (46) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK10E8621C2 (61) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: ;tag=6F0A037C-A94 (55) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: "9971" ;tag=as4d4a0895 (62) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Date: Fri, 10 Nov 2006 12:20:32 GMT (35) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Max-Forwards: 70 (16) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: CSeq: 101 ACK (13) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Content-Length: 0 (17) [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:14286 handle_request: **** Received ACK (6) - Command in SIP ACK [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:2033 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #39 [Nov 10 19:16:15] DEBUG[8966]: chan_sip.c:2043 __sip_ack: Stopping retransmission on '5740ebc11cc18005748a10d022fd1342@10.10.119.251' of Response 101: Match Not Found centrala*CLI> <--- SIP read from 10.10.119.225:50914 ---> INVITE sip:9971@10.10.119.251:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK10E8742F From: ;tag=6F0A037C-A94 To: "9971" ;tag=as4d4a0895 Date: Fri, 10 Nov 2006 12:21:13 GMT Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 Supported: 100rel,timer,resource-priority,replaces Min-SE: 1800 Cisco-Guid: 2859328702-1877742043-2740823462-4050708206 User-Agent: Cisco-SIPGateway/IOS-12.x Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER CSeq: 102 INVITE Max-Forwards: 70 Timestamp: 1163161273 Contact: Expires: 180 Allow-Events: telephone-event Content-Type: application/sdp Content-Length: 197 v=0 o=CiscoSystemsSIP-GW-UserAgent 268 90 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 16578 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: INVITE sip:9971@10.10.119.251:5060 SIP/2.0 (49) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK10E8742F (60) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: ;tag=6F0A037C-A94 (55) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: "9971" ;tag=as4d4a0895 (62) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Date: Fri, 10 Nov 2006 12:21:13 GMT (35) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Supported: 100rel,timer,resource-priority,replaces (50) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: Min-SE: 1800 (13) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Cisco-Guid: 2859328702-1877742043-2740823462-4050708206 (55) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: User-Agent: Cisco-SIPGateway/IOS-12.x (37) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 11: CSeq: 102 INVITE (16) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 12: Max-Forwards: 70 (16) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 13: Timestamp: 1163161273 (21) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 14: Contact: (46) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 15: Expires: 180 (12) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 16: Allow-Events: telephone-event (29) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 17: Content-Type: application/sdp (29) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 18: Content-Length: 197 (19) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 19: (0) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 268 90 IN IP4 10.10.119.225 (60) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: s=SIP Call (10) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: m=audio 16578 RTP/AVP 8 (23) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=ptime:20 (10) --- (19 headers 9 lines) --- [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:14286 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 10.10.119.225 : 5060 (no NAT) Found RTP audio format 8 Peer audio RTP is at port 10.10.119.225:16578 [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4791 process_sdp: Peer doesn't provide T.38 UDPTL Found description format PCMA for ID 8 Got unsupported a:ptime in SDP offer [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:5003 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081c4b10 Capabilities: us - 0x8 (alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.119.225:16578 [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:5080 process_sdp: We're settling with these formats: 0x8 (alaw) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:5087 process_sdp: We have an owner, now see if we need to change this call [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:13130 handle_request_invite: Got a SIP re-invite for call 5740ebc11cc18005748a10d022fd1342@10.10.119.251 [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:13219 handle_request_invite: SIP/10.10.119.225-081c4b10: This call is UP.... [Nov 10 19:16:55] WARNING[8966]: chan_sip.c:13284 handle_request_invite: RTP re-invite after T38 session not handled yet ! <--- Reliably Transmitting (no NAT) to 10.10.119.225:5060 ---> SIP/2.0 488 Not Acceptable Here (unsupported) Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK10E8742F;received=10.10.119.225 From: ;tag=6F0A037C-A94 To: "9971" ;tag=as4d4a0895 Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 <------------> [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:1931 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #40 Scheduling destruction of SIP dialog '5740ebc11cc18005748a10d022fd1342@10.10.119.251' in 32000 ms (Method: INVITE) [Nov 10 19:16:55] DEBUG[9063]: rtp.c:2693 bridge_native_loop: Oooh, 'SIP/10.10.119.225-081c4b10' changed end address to 10.10.119.225:16578 (format 8) [Nov 10 19:16:55] DEBUG[9063]: rtp.c:2695 bridge_native_loop: Oooh, 'SIP/10.10.119.225-081c4b10' changed end vaddress to 0.0.0.0:0 (format 8) [Nov 10 19:16:55] DEBUG[9063]: rtp.c:2697 bridge_native_loop: Oooh, 'SIP/10.10.119.225-081c4b10' was 0.0.0.0:0/(format 8) [Nov 10 19:16:55] DEBUG[9063]: rtp.c:2699 bridge_native_loop: Oooh, 'SIP/10.10.119.225-081c4b10' was 0.0.0.0:0/(format 8) centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> ACK sip:9971@10.10.119.251:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK10E8742F From: ;tag=6F0A037C-A94 To: "9971" ;tag=as4d4a0895 Date: Fri, 10 Nov 2006 12:21:13 GMT Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 Max-Forwards: 70 CSeq: 102 ACK Content-Length: 0 <-------------> [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: ACK sip:9971@10.10.119.251:5060 SIP/2.0 (46) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.225:5060;branch=z9hG4bK10E8742F (60) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: ;tag=6F0A037C-A94 (55) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: "9971" ;tag=as4d4a0895 (62) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Date: Fri, 10 Nov 2006 12:21:13 GMT (35) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Max-Forwards: 70 (16) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: CSeq: 102 ACK (13) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Content-Length: 0 (17) [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:14286 handle_request: **** Received ACK (6) - Command in SIP ACK [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:2033 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #40 [Nov 10 19:16:55] DEBUG[8966]: chan_sip.c:2043 __sip_ack: Stopping retransmission on '5740ebc11cc18005748a10d022fd1342@10.10.119.251' of Response 102: Match Not Found centrala*CLI> <--- SIP read from 10.10.119.248:5060 ---> BYE sip:8367@10.10.119.251 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-28b2671b From: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 To: ;tag=as2c191251 Call-ID: 94ebae26-3857881e@10.10.119.248 CSeq: 102 BYE Max-Forwards: 70 User-Agent: Linksys/SPA9000-3.2.8(d) Allow-Events: talk, hold, conference Content-Length: 0 <-------------> [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: BYE sip:8367@10.10.119.251 SIP/2.0 (42) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-28b2671b (61) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 (79) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=as2c191251 (51) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Call-ID: 94ebae26-3857881e@10.10.119.248 (42) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: CSeq: 102 BYE (13) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Max-Forwards: 70 (16) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: User-Agent: Linksys/SPA9000-3.2.8(d) (36) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Allow-Events: talk, hold, conference (36) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Content-Length: 0 (17) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:14286 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 10.10.119.248 : 5060 (no NAT) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:13859 handle_request_bye: Received bye, issuing owner hangup . <--- Transmitting (no NAT) to 10.10.119.248:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-28b2671b;received=10.10.119.248 From: 9971 ;tag=75f0b686802f1b3eo2;ref=1000 To: ;tag=as2c191251 Call-ID: 94ebae26-3857881e@10.10.119.248 CSeq: 102 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Nov 10 19:16:56] DEBUG[9063]: rtp.c:2742 bridge_native_loop: Oooh, got a hangup [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:16511 sip_set_rtp_peer: Sending reinvite on SIP '5740ebc11cc18005748a10d022fd1342@10.10.119.251' - It's audio soon redirected to IP 10.10.119.251 [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:5509 reqprep: Strict routing enforced for session 5740ebc11cc18005748a10d022fd1342@10.10.119.251 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.119.225, port 5060 [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:6053 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:6054 add_sdp: ** Our prefcodec: 0x8 (alaw) Audio is at 10.10.119.251 port 11100 Adding codec 0x8 (alaw) to SDP [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:6185 add_sdp: -- Done with adding codecs to SDP [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:6230 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:1587 initialize_initreq: Initializing already initialized SIP dialog 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (presumably reinvite) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 0: INVITE sip:8367@10.10.119.225:5060 SIP/2.0 (50) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK323cae8b;rport (66) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 2: From: "9971" ;tag=as4d4a0895 (64) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=6F0A037C-A94 (53) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 4: Contact: (40) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 6: CSeq: 103 INVITE (16) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 8: Max-Forwards: 70 (16) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 10: Supported: replaces (19) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 12: Content-Type: application/sdp (29) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 13: Content-Length: 188 (19) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4467 parse_request: Header 14: (0) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: o=root 9063 9065 IN IP4 10.10.119.251 (39) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: s=session (9) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.251 (24) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: m=audio 11100 RTP/AVP 8 (23) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: a=silenceSupp:off - - - - (25) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: a=ptime:20 (10) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:4499 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 10.10.119.225:5060: INVITE sip:8367@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK323cae8b;rport From: "9971" ;tag=as4d4a0895 To: ;tag=6F0A037C-A94 Contact: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 CSeq: 103 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 188 v=0 o=root 9063 9065 IN IP4 10.10.119.251 s=session c=IN IP4 10.10.119.251 t=0 0 m=audio 11100 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:1931 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #42 [Nov 10 19:16:56] DEBUG[9063]: channel.c:3918 ast_channel_bridge: Returning from native bridge, channels: SIP/9971-081b1ee0, SIP/10.10.119.225-081c4b10 [Nov 10 19:16:56] DEBUG[9063]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/10.10.119.225-081c4b10' [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:3245 sip_hangup: Hangup call SIP/10.10.119.225-081c4b10, SIP callid 5740ebc11cc18005748a10d022fd1342@10.10.119.251) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:3253 sip_hangup: update_call_counter(8367) - decrement call limit counter on hangup [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:2946 update_call_counter: Updating call counter for outgoing call Scheduling destruction of SIP dialog '5740ebc11cc18005748a10d022fd1342@10.10.119.251' in 32000 ms (Method: ACK) [Nov 10 19:16:56] DEBUG[9063]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/10.10.119.225-081c4b10 [Nov 10 19:16:56] DEBUG[8947]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 10.10.119.225 [Nov 10 19:16:56] DEBUG[8947]: chan_sip.c:14872 sip_devicestate: Checking device state for peer 10.10.119.225 [Nov 10 19:16:56] DEBUG[8947]: devicestate.c:287 do_state_change: Changing state for SIP/10.10.119.225 - state 1 (Not in use) [Nov 10 19:16:56] DEBUG[9067]: app_queue.c:546 changethread: Device 'SIP/10.10.119.225' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 10 19:16:56] DEBUG[9063]: rtp.c:1418 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Nov 10 19:16:56] DEBUG[9063]: app_dial.c:1639 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Nov 10 19:16:56] DEBUG[9063]: pbx.c:2363 __ast_pbx_run: Spawn extension (default,8367,1) exited non-zero on 'SIP/9971-081b1ee0' == Spawn extension (default, 8367, 1) exited non-zero on 'SIP/9971-081b1ee0' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"9971" <9971>' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '9971' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '8367' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/9971-081b1ee0' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/10.10.119.225-081c4b10' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/10.10.119.225/8367|60|r' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 19:16:02' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 19:16:09' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 19:16:56' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '54' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '47' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1163182562.8' [Nov 10 19:16:56] DEBUG[9063]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 19:16:56] DEBUG[9063]: channel.c:1606 ast_hangup: Hanging up channel 'SIP/9971-081b1ee0' [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:3245 sip_hangup: Hangup call SIP/9971-081b1ee0, SIP callid 94ebae26-3857881e@10.10.119.248) [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:3253 sip_hangup: update_call_counter(9971) - decrement call limit counter on hangup [Nov 10 19:16:56] DEBUG[9063]: chan_sip.c:2946 update_call_counter: Updating call counter for outgoing call [Nov 10 19:16:56] DEBUG[9063]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9971-081b1ee0 [Nov 10 19:16:56] DEBUG[8947]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9971 [Nov 10 19:16:56] DEBUG[8947]: chan_sip.c:14872 sip_devicestate: Checking device state for peer 9971 [Nov 10 19:16:56] DEBUG[8947]: devicestate.c:287 do_state_change: Changing state for SIP/9971 - state 1 (Not in use) [Nov 10 19:16:56] DEBUG[9068]: app_queue.c:546 changethread: Device 'SIP/9971' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. centrala*CLI> <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK323cae8b;rport From: "9971" ;tag=as4d4a0895 To: ;tag=6F0A037C-A94 Date: Fri, 10 Nov 2006 12:21:14 GMT Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 103 INVITE Allow-Events: telephone-event Content-Length: 0 <-------------> [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 100 Trying (18) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK323cae8b;rport (66) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: "9971" ;tag=as4d4a0895 (64) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=6F0A037C-A94 (53) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Date: Fri, 10 Nov 2006 12:21:14 GMT (35) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: CSeq: 103 INVITE (16) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Allow-Events: telephone-event (29) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Content-Length: 0 (17) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:2076 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #42 - INVITE (got response) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:2085 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '5740ebc11cc18005748a10d022fd1342@10.10.119.251' Request 103: Found [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:11408 handle_response_invite: SIP response 100 to standard invite [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:5509 reqprep: Strict routing enforced for session 5740ebc11cc18005748a10d022fd1342@10.10.119.251 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.119.225, port 5060 Reliably Transmitting (no NAT) to 10.10.119.225:5060: BYE sip:8367@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK4c3ce72a;rport From: "9971" ;tag=as4d4a0895 To: ;tag=6F0A037C-A94 Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:1931 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #44 Scheduling destruction of SIP dialog '5740ebc11cc18005748a10d022fd1342@10.10.119.251' in 32000 ms (Method: ACK) Really destroying SIP dialog '94ebae26-3857881e@10.10.119.248' Method: BYE <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK323cae8b;rport From: "9971" ;tag=as4d4a0895 To: ;tag=6F0A037C-A94 Date: Fri, 10 Nov 2006 12:21:14 GMT Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 103 INVITE Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER Allow-Events: telephone-event Contact: Content-Type: application/sdp Content-Length: 197 v=0 o=CiscoSystemsSIP-GW-UserAgent 268 91 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 16578 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 200 OK (14) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK323cae8b;rport (66) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: "9971" ;tag=as4d4a0895 (64) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=6F0A037C-A94 (53) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Date: Fri, 10 Nov 2006 12:21:14 GMT (35) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: CSeq: 103 INVITE (16) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER (97) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Allow-Events: telephone-event (29) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: Contact: (46) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 11: Content-Type: application/sdp (29) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 12: Content-Length: 197 (19) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 13: (0) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: v=0 (3) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: o=CiscoSystemsSIP-GW-UserAgent 268 91 IN IP4 10.10.119.225 (60) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: s=SIP Call (10) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: t=0 0 (5) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: m=audio 16578 RTP/AVP 8 (23) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: c=IN IP4 10.10.119.225 (24) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4499 parse_request: Line: a=ptime:20 (10) --- (13 headers 9 lines) --- [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:2025 __sip_ack: Acked pending invite 103 [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:2043 __sip_ack: Stopping retransmission on '5740ebc11cc18005748a10d022fd1342@10.10.119.251' of Request 103: Match Not Found [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:11408 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 Peer audio RTP is at port 10.10.119.225:16578 [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4791 process_sdp: Peer doesn't provide T.38 UDPTL Found description format PCMA for ID 8 Got unsupported a:ptime in SDP offer [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:5003 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x8 (alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.10.119.225:16578 [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:5080 process_sdp: We're settling with these formats: 0x8 (alaw) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:2946 update_call_counter: Updating call counter for outgoing call [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:7755 build_route: build_route: Retaining previous route: [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:5509 reqprep: Strict routing enforced for session 5740ebc11cc18005748a10d022fd1342@10.10.119.251 set_destination: Parsing for address/port to send to set_destination: set destination to 10.10.119.225, port 5060 Transmitting (no NAT) to 10.10.119.225:5060: ACK sip:8367@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK00478644;rport From: "9971" ;tag=as4d4a0895 To: ;tag=6F0A037C-A94 Contact: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 CSeq: 103 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- <--- SIP read from 10.10.119.225:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK4c3ce72a;rport From: "9971" ;tag=as4d4a0895 To: ;tag=6F0A037C-A94 Date: Fri, 10 Nov 2006 12:21:14 GMT Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 104 BYE Reason: Q.850;cause=16 Content-Length: 0 <-------------> [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 0: SIP/2.0 200 OK (14) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 1: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK4c3ce72a;rport (66) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 2: From: "9971" ;tag=as4d4a0895 (64) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 3: To: ;tag=6F0A037C-A94 (53) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 4: Date: Fri, 10 Nov 2006 12:21:14 GMT (35) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 5: Call-ID: 5740ebc11cc18005748a10d022fd1342@10.10.119.251 (57) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 6: Server: Cisco-SIPGateway/IOS-12.x (33) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 7: CSeq: 104 BYE (13) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 8: Reason: Q.850;cause=16 (22) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 9: Content-Length: 0 (17) [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:4467 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:2033 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #44 [Nov 10 19:16:56] DEBUG[8966]: chan_sip.c:2043 __sip_ack: Stopping retransmission on '5740ebc11cc18005748a10d022fd1342@10.10.119.251' of Request 104: Match Not Found Really destroying SIP dialog '5740ebc11cc18005748a10d022fd1342@10.10.119.251' Method: ACK centrala*CLI> exit centrala:~#