centrala*CLI> centrala*CLI> centrala*CLI> centrala*CLI> centrala*CLI> <--- SIP read from 10.10.119.248:5060 ---> INVITE sip:8344@10.10.119.251 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-d3713819 From: 9971 ;tag=318bab21b44e20b7o2;ref=1000 To: Remote-Party-ID: 9971 ;screen=yes;party=calling Call-ID: 4f9dc24-aad06b8f@10.10.119.248 CSeq: 101 INVITE Max-Forwards: 70 Contact: 9971 Expires: 240 ser-Agent: Linksys/SPA9000-3.2.8(d) Allow-Events: talk, hold, conference Content-Length: 401 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 87688931 87688931 IN IP4 192.168.0.1 s=- c=IN IP4 10.10.119.248 t=0 0 m=audio 16442 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 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 0 [ 45]: INVITE sip:8344@10.10.119.251 SIP/2.0 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 1 [ 61]: Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-d3713819 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 2 [ 79]: From: 9971 ;tag=318bab21b44e20b7o2;ref=1000 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 3 [ 36]: To: [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 4 [ 83]: Remote-Party-ID: 9971 ;screen=yes;party=calling [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 5 [ 41]: Call-ID: 4f9dc24-aad06b8f@10.10.119.248 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 6 [ 16]: CSeq: 101 INVITE [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 7 [ 16]: Max-Forwards: 70 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 8 [ 55]: Contact: 9971 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 9 [ 12]: Expires: 240 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 10 [ 36]: User-Agent: Linksys/SPA9000-3.2.8(d) [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 11 [ 36]: Allow-Events: talk, hold, conference [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 12 [ 19]: Content-Length: 401 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 13 [ 61]: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 14 [ 19]: Supported: x-sipura [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 15 [ 29]: Content-Type: application/sdp [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 16 [ 0]: [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 0 [ 3]: v=0 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 1 [ 40]: o=- 87688931 87688931 IN IP4 192.168.0.1 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 2 [ 3]: s=- [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 3 [ 24]: c=IN IP4 10.10.119.248 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 4 [ 5]: t=0 0 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 5 [ 45]: m=audio 16442 RTP/AVP 18 0 2 4 8 96 97 98 101 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 6 [ 22]: a=rtpmap:18 G729a/8000 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 8 [ 23]: a=rtpmap:2 G726-32/8000 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 9 [ 20]: a=rtpmap:4 G723/8000 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 11 [ 24]: a=rtpmap:96 G726-40/8000 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 12 [ 24]: a=rtpmap:97 G726-24/8000 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 13 [ 24]: a=rtpmap:98 G726-16/8000 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 14 [ 33]: a=rtpmap:101 telephone-event/8000 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 15 [ 15]: a=fmtp:101 0-15 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 16 [ 10]: a=ptime:30 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 17 [ 10]: a=sendrecv [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 18 [ 0]: --- (16 headers 19 lines) --- [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:2669 do_setnat: Setting NAT on RTP to Off [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:2679 do_setnat: Setting NAT on UDPTL to Off [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4358 sip_alloc: Allocating new SIP dialog for 4f9dc24-aad06b8f@10.10.119.248 - INVITE (With RTP) [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:14624 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:1707 parse_sip_options: Begin: parsing SIP "Supported: x-sipura" [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:1715 parse_sip_options: Found SIP option: -x-sipura- [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:1727 parse_sip_options: Found private SIP option, not supported: x-sipura Sending to 10.10.119.248 : 5060 (no NAT) [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:13331 handle_request_invite: Initializing initreq for method INVITE - callid 4f9dc24-aad06b8f@10.10.119.248 Using INVITE request as basis request - 4f9dc24-aad06b8f@10.10.119.248 Found user '9971' for '9971' [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:2669 do_setnat: Setting NAT on RTP to Off [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:2679 do_setnat: Setting NAT on UDPTL to Off 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 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4923 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.119.248:16442 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 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:5153 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x108 (alaw|g729), peer - audio=0xd0d (g723|ulaw|alaw|g726|g729|ilbc)/video=0x0 (nothing), combined - 0x108 (alaw|g729) 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:16442 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:5230 process_sdp: We're settling with these formats: 0x108 (alaw|g729) [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:13408 handle_request_invite: Checking SIP call limits for device 9971 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:3091 update_call_counter: Updating call counter for incoming call Looking for 8344 in default (domain 10.10.119.251) [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:3867 sip_new: *** Our native formats are 0x8 (alaw) [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:3868 sip_new: *** Joint capabilities are 0x108 (alaw|g729) [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:3869 sip_new: *** Our capabilities are 0x108 (alaw|g729) [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:3870 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:3893 sip_new: This channel will not be able to handle video. [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:7953 build_route: build_route: Contact hop: 9971 list_route: hop: [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:13481 handle_request_invite: SIP/9971-081b1c08: 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-d3713819;received=10.10.119.248 From: 9971 ;tag=318bab21b44e20b7o2;ref=1000 To: Call-ID: 4f9dc24-aad06b8f@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 20 22:33:00] DEBUG[2444]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9971-081b1c08 [Nov 20 22:33:00] DEBUG[2425]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9971 [Nov 20 22:33:00] DEBUG[2425]: chan_sip.c:15222 sip_devicestate: Checking device state for peer 9971 [Nov 20 22:33:00] DEBUG[2425]: devicestate.c:287 do_state_change: Changing state for SIP/9971 - state 1 (Not in use) [Nov 20 22:33:00] DEBUG[2483]: pbx.c:1685 pbx_extension_helper: Launching 'Dial' -- Executing [8344@default:1] Dial("SIP/9971-081b1c08", "SIP/10.10.119.225/8344|60|r") in new stack ast_request: tech: SIP capabilities are 0xffff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g726aal2|g722) ast_request: request for format 0x8 (alaw) [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:15281 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw) [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4358 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) sip_request_call: we are setting prefcodec to 0x8 (alaw) [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:3867 sip_new: *** Our native formats are 0x100 (g729) [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:3868 sip_new: *** Joint capabilities are 0x0 (nothing) [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:3869 sip_new: *** Our capabilities are 0x508 (alaw|g729|ilbc) [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:3870 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:3872 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:3893 sip_new: This channel will not be able to handle video. [Nov 20 22:33:00] DEBUG[2484]: app_queue.c:568 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 20 22:33:00] DEBUG[2483]: chan_sip.c:16872 sip_set_rtp_peer: Early remote bridge setting SIP '412f6751271edc7931c93b4437801a99@10.10.119.251' - Sending media to 10.10.119.248 [Nov 20 22:33:00] DEBUG[2483]: rtp.c:1589 ast_rtp_make_compatible: Seeded SDP of 'SIP/10.10.119.225-081d01b0' with that of 'SIP/9971-081b1c08' [Nov 20 22:33:00] DEBUG[2483]: channel.c:3202 ast_channel_inherit_variables: Not copying variable STACK-default-8344-1. [Nov 20 22:33:00] DEBUG[2483]: channel.c:3202 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Nov 20 22:33:00] DEBUG[2483]: channel.c:3202 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Nov 20 22:33:00] DEBUG[2483]: channel.c:3202 ast_channel_inherit_variables: Not copying variable SIPURI. [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:2917 sip_call: Outgoing Call for 8344 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:3091 update_call_counter: Updating call counter for outgoing call [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:2926 sip_call: jointcapability 0x408 (alaw|ilbc) [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:2934 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:6227 add_sdp: ** Our capability: 0x408 (alaw|ilbc) Video flag: False [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:6228 add_sdp: ** Our prefcodec: 0x8 (alaw) Audio is at 10.10.119.251 port 14116 Adding codec 0x8 (alaw) to SDP Adding codec 0x400 (ilbc) to SDP [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:6318 add_sdp: added pref codec (400) to sdp Adding non-codec 0x1 (telephone-event) to SDP [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:6357 add_sdp: -- Done with adding codecs to SDP [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:6401 add_sdp: Done building SDP. Settling with this capability: 0x408 (alaw|ilbc) [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:1655 initialize_initreq: Initializing initreq for method INVITE - callid 412f6751271edc7931c93b4437801a99@10.10.119.251 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 0 [ 45]: INVITE sip:8344@10.10.119.225 SIP/2.0 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK3aef7a86;rport [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 2 [ 16]: Max-Forwards: 70 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 3 [ 64]: From: "9971" ;tag=as0ce8b33f [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 4 [ 36]: To: [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 5 [ 40]: Contact: [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 6 [ 57]: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 7 [ 16]: CSeq: 102 INVITE [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 8 [ 24]: User-Agent: Asterisk PBX [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 9 [ 35]: Date: Mon, 20 Nov 2006 21:33:00 GMT [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 11 [ 19]: Supported: replaces [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 12 [ 29]: Content-Type: application/sdp [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 13 [ 19]: Content-Length: 289 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 14 [ 0]: [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 0 [ 3]: v=0 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 1 [ 39]: o=root 2483 2483 IN IP4 10.10.119.248 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 2 [ 9]: s=session [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 3 [ 24]: c=IN IP4 10.10.119.248 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 4 [ 5]: t=0 0 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 5 [ 30]: m=audio 16442 RTP/AVP 8 97 101 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 7 [ 21]: a=rtpmap:97 iLBC/8000 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 8 [ 17]: a=fmtp:97 mode=30 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 10 [ 15]: a=fmtp:101 0-16 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 11 [ 25]: a=silenceSupp:off - - - - [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 12 [ 10]: a=ptime:20 [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 13 [ 10]: a=sendrecv Reliably Transmitting (no NAT) to 10.10.119.225:5060: INVITE sip:8344@10.10.119.225 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK3aef7a86;rport Max-Forwards: 70 From: "9971" ;tag=as0ce8b33f To: Contact: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 CSeq: 102 INVITE User-Agent: Asterisk PBX Date: Mon, 20 Nov 2006 21:33:00 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 289 v=0 o=root 2483 2483 IN IP4 10.10.119.248 s=session c=IN IP4 10.10.119.248 t=0 0 m=audio 16442 RTP/AVP 8 97 101 a=rtpmap:8 PCMA/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Nov 20 22:33:00] DEBUG[2483]: chan_sip.c:1997 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #32 -- Called 10.10.119.225/8344 centrala*CLI> <--- 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-d3713819;received=10.10.119.248 From: 9971 ;tag=318bab21b44e20b7o2;ref=1000 To: ;tag=as6c6c1374 Call-ID: 4f9dc24-aad06b8f@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=z9hG4bK3aef7a86;rport From: "9971" ;tag=as0ce8b33f To: ;tag=A33E5334-A9F Date: Mon, 20 Nov 2006 15:37:46 GMT Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow-Events: telephone-event Content-Length: 0 <-------------> [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 0 [ 18]: SIP/2.0 100 Trying [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK3aef7a86;rport [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 2 [ 64]: From: "9971" ;tag=as0ce8b33f [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 3 [ 53]: To: ;tag=A33E5334-A9F [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 4 [ 35]: Date: Mon, 20 Nov 2006 15:37:46 GMT [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 5 [ 57]: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 6 [ 33]: Server: Cisco-SIPGateway/IOS-12.x [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 7 [ 16]: CSeq: 102 INVITE [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 8 [ 29]: Allow-Events: telephone-event [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 9 [ 17]: Content-Length: 0 [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 10 [ 0]: --- (10 headers 0 lines) --- [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:2140 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #32 - INVITE (got response) [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:2149 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '412f6751271edc7931c93b4437801a99@10.10.119.251' Request 102: Found [Nov 20 22:33:00] DEBUG[2444]: chan_sip.c:11708 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=z9hG4bK3aef7a86;rport From: "9971" ;tag=as0ce8b33f To: ;tag=A33E5334-A9F Date: Mon, 20 Nov 2006 15:37:46 GMT Call-ID: 412f6751271edc7931c93b4437801a99@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: 200 v=0 o=CiscoSystemsSIP-GW-UserAgent 5996 8500 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 17622 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 0 [ 28]: SIP/2.0 183 Session Progress [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK3aef7a86;rport [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 2 [ 64]: From: "9971" ;tag=as0ce8b33f [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 3 [ 53]: To: ;tag=A33E5334-A9F [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 4 [ 35]: Date: Mon, 20 Nov 2006 15:37:46 GMT [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 5 [ 57]: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 6 [ 33]: Server: Cisco-SIPGateway/IOS-12.x [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 7 [ 16]: CSeq: 102 INVITE [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 8 [ 97]: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 9 [ 29]: Allow-Events: telephone-event [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 10 [ 46]: Contact: [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 11 [ 29]: Content-Type: application/sdp [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 12 [ 46]: Content-Disposition: session;handling=required [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 13 [ 19]: Content-Length: 200 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 14 [ 0]: [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 0 [ 3]: v=0 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 1 [ 63]: o=CiscoSystemsSIP-GW-UserAgent 5996 8500 IN IP4 10.10.119.225 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 2 [ 10]: s=SIP Call [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 3 [ 24]: c=IN IP4 10.10.119.225 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 4 [ 5]: t=0 0 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 5 [ 23]: m=audio 17622 RTP/AVP 8 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 6 [ 24]: c=IN IP4 10.10.119.225 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 8 [ 10]: a=ptime:20 --- (14 headers 9 lines) --- [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:2149 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '412f6751271edc7931c93b4437801a99@10.10.119.251' Request 102: Found [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:11708 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 8 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4923 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.119.225:17622 Found description format PCMA for ID 8 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:5153 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081d01b0 Capabilities: us - 0x508 (alaw|g729|ilbc), 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:17622 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:5230 process_sdp: We're settling with these formats: 0x8 (alaw) [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:5237 process_sdp: We have an owner, now see if we need to change this call [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:5242 process_sdp: Oooh, we need to change our audio formats since our peer supports only 0x8 (alaw) and not 0x100 (g729) [Nov 20 22:33:01] WARNING[2444]: channel.c:2706 set_format: Unable to find a codec translation path from alaw to g729 [Nov 20 22:33:01] WARNING[2444]: channel.c:2706 set_format: Unable to find a codec translation path from alaw to g729 -- SIP/10.10.119.225-081d01b0 is making progress passing it to SIP/9971-081b1c08 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=z9hG4bK3aef7a86;rport From: "9971" ;tag=as0ce8b33f To: ;tag=A33E5334-A9F Date: Mon, 20 Nov 2006 15:37:46 GMT Call-ID: 412f6751271edc7931c93b4437801a99@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: 200 v=0 o=CiscoSystemsSIP-GW-UserAgent 5996 8500 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 17622 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 0 [ 28]: SIP/2.0 183 Session Progress [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK3aef7a86;rport [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 2 [ 64]: From: "9971" ;tag=as0ce8b33f [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 3 [ 53]: To: ;tag=A33E5334-A9F [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 4 [ 35]: Date: Mon, 20 Nov 2006 15:37:46 GMT [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 5 [ 57]: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 6 [ 33]: Server: Cisco-SIPGateway/IOS-12.x [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 7 [ 16]: CSeq: 102 INVITE [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 8 [ 97]: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 9 [ 29]: Allow-Events: telephone-event [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 10 [ 46]: Contact: [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 11 [ 29]: Content-Type: application/sdp [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 12 [ 46]: Content-Disposition: session;handling=required [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 13 [ 19]: Content-Length: 200 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 14 [ 0]: [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 0 [ 3]: v=0 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 1 [ 63]: o=CiscoSystemsSIP-GW-UserAgent 5996 8500 IN IP4 10.10.119.225 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 2 [ 10]: s=SIP Call [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 3 [ 24]: c=IN IP4 10.10.119.225 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 4 [ 5]: t=0 0 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 5 [ 23]: m=audio 17622 RTP/AVP 8 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 6 [ 24]: c=IN IP4 10.10.119.225 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 8 [ 10]: a=ptime:20 --- (14 headers 9 lines) --- [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:2149 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '412f6751271edc7931c93b4437801a99@10.10.119.251' Request 102: Found [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:11708 handle_response_invite: SIP response 183 to standard invite Found RTP audio format 8 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:4923 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.119.225:17622 Found description format PCMA for ID 8 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:5153 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081d01b0 Capabilities: us - 0x508 (alaw|g729|ilbc), 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:17622 [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:5230 process_sdp: We're settling with these formats: 0x8 (alaw) [Nov 20 22:33:01] DEBUG[2444]: chan_sip.c:5237 process_sdp: We have an owner, now see if we need to change this call -- SIP/10.10.119.225-081d01b0 is making progress passing it to SIP/9971-081b1c08 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=z9hG4bK3aef7a86;rport From: "9971" ;tag=as0ce8b33f To: ;tag=A33E5334-A9F Date: Mon, 20 Nov 2006 15:37:46 GMT Call-ID: 412f6751271edc7931c93b4437801a99@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: 200 v=0 o=CiscoSystemsSIP-GW-UserAgent 5996 8500 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 17622 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 0 [ 14]: SIP/2.0 200 OK [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK3aef7a86;rport [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 2 [ 64]: From: "9971" ;tag=as0ce8b33f [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 3 [ 53]: To: ;tag=A33E5334-A9F [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 4 [ 35]: Date: Mon, 20 Nov 2006 15:37:46 GMT [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 5 [ 57]: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 6 [ 33]: Server: Cisco-SIPGateway/IOS-12.x [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 7 [ 16]: CSeq: 102 INVITE [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 8 [ 97]: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 9 [ 29]: Allow-Events: telephone-event [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 10 [ 46]: Contact: [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 11 [ 29]: Content-Type: application/sdp [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 12 [ 46]: Content-Disposition: session;handling=required [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 13 [ 19]: Content-Length: 200 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 14 [ 0]: [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 0 [ 3]: v=0 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 1 [ 63]: o=CiscoSystemsSIP-GW-UserAgent 5996 8500 IN IP4 10.10.119.225 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 2 [ 10]: s=SIP Call [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 3 [ 24]: c=IN IP4 10.10.119.225 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 4 [ 5]: t=0 0 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 5 [ 23]: m=audio 17622 RTP/AVP 8 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 6 [ 24]: c=IN IP4 10.10.119.225 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 8 [ 10]: a=ptime:20 --- (14 headers 9 lines) --- [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:2091 __sip_ack: Acked pending invite 102 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:2106 __sip_ack: Stopping retransmission on '412f6751271edc7931c93b4437801a99@10.10.119.251' of Request 102: Match Found [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:11708 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4923 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.119.225:17622 Found description format PCMA for ID 8 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:5153 process_sdp: T38 state changed to 0 on channel SIP/10.10.119.225-081d01b0 Capabilities: us - 0x508 (alaw|g729|ilbc), 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:17622 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:5230 process_sdp: We're settling with these formats: 0x8 (alaw) [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:5237 process_sdp: We have an owner, now see if we need to change this call [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:3091 update_call_counter: Updating call counter for outgoing call --- set_address_from_contact host '10.10.119.225' [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:7953 build_route: build_route: Contact hop: list_route: hop: [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:5662 reqprep: Strict routing enforced for session 412f6751271edc7931c93b4437801a99@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:8344@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK4b0c430a;rport Max-Forwards: 70 From: "9971" ;tag=as0ce8b33f To: ;tag=A33E5334-A9F Contact: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 CSeq: 102 ACK User-Agent: Asterisk PBX Content-Length: 0 --- [Nov 20 22:33:02] DEBUG[2483]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/10.10.119.225-081d01b0 [Nov 20 22:33:02] DEBUG[2425]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 10.10.119.225 [Nov 20 22:33:02] DEBUG[2425]: chan_sip.c:15222 sip_devicestate: Checking device state for peer 10.10.119.225 [Nov 20 22:33:02] DEBUG[2425]: channel.c:935 channel_find_locked: Avoiding initial deadlock for channel '0x81d4290' -- SIP/10.10.119.225-081d01b0 answered SIP/9971-081b1c08 [Nov 20 22:33:02] DEBUG[2483]: chan_sip.c:16872 sip_set_rtp_peer: Early remote bridge setting SIP '4f9dc24-aad06b8f@10.10.119.248' - Sending media to 10.10.119.225 [Nov 20 22:33:02] DEBUG[2483]: rtp.c:1524 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/9971-081b1c08' with that of 'SIP/10.10.119.225-081d01b0' [Nov 20 22:33:02] DEBUG[2483]: channel.c:2735 set_format: Set channel SIP/10.10.119.225-081d01b0 to write format alaw [Nov 20 22:33:02] DEBUG[2483]: channel.c:2735 set_format: Set channel SIP/10.10.119.225-081d01b0 to read format alaw [Nov 20 22:33:02] DEBUG[2483]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9971-081b1c08 [Nov 20 22:33:02] DEBUG[2483]: chan_sip.c:3535 sip_answer: SIP answering channel: SIP/9971-081b1c08 [Nov 20 22:33:02] DEBUG[2483]: chan_sip.c:6456 transmit_response_with_sdp: Setting framing from config on incoming call [Nov 20 22:33:02] DEBUG[2483]: chan_sip.c:6227 add_sdp: ** Our capability: 0x108 (alaw|g729) Video flag: True [Nov 20 22:33:02] DEBUG[2483]: chan_sip.c:6228 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 10.10.119.251 port 17440 Adding codec 0x8 (alaw) to SDP [Nov 20 22:33:02] DEBUG[2483]: chan_sip.c:6318 add_sdp: added pref codec (8) to sdp Adding codec 0x100 (g729) to SDP [Nov 20 22:33:02] DEBUG[2483]: chan_sip.c:6318 add_sdp: added pref codec (100) to sdp Adding non-codec 0x1 (telephone-event) to SDP [Nov 20 22:33:02] DEBUG[2483]: chan_sip.c:6357 add_sdp: -- Done with adding codecs to SDP [Nov 20 22:33:02] DEBUG[2483]: chan_sip.c:6401 add_sdp: Done building SDP. Settling with this capability: 0x108 (alaw|g729) centrala*CLI> <--- 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-d3713819;received=10.10.119.248 From: 9971 ;tag=318bab21b44e20b7o2;ref=1000 To: ;tag=as6c6c1374 Call-ID: 4f9dc24-aad06b8f@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: 291 v=0 o=root 2483 2483 IN IP4 10.10.119.225 s=session c=IN IP4 10.10.119.225 t=0 0 m=audio 17622 RTP/AVP 8 18 101 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Nov 20 22:33:02] DEBUG[2483]: chan_sip.c:1997 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #34 -- Native bridging SIP/9971-081b1c08 and SIP/10.10.119.225-081d01b0 [Nov 20 22:33:02] DEBUG[2425]: devicestate.c:287 do_state_change: Changing state for SIP/10.10.119.225 - state 2 (In use) [Nov 20 22:33:02] DEBUG[2485]: app_queue.c:568 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 20 22:33:02] DEBUG[2425]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9971 [Nov 20 22:33:02] DEBUG[2425]: chan_sip.c:15222 sip_devicestate: Checking device state for peer 9971 [Nov 20 22:33:02] DEBUG[2425]: devicestate.c:287 do_state_change: Changing state for SIP/9971 - state 1 (Not in use) [Nov 20 22:33:02] DEBUG[2486]: app_queue.c:568 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.248:5060 ---> ACK sip:8344@10.10.119.251 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-d9013913 From: 9971 ;tag=318bab21b44e20b7o2;ref=1000 To: ;tag=as6c6c1374 Call-ID: 4f9dc24-aad06b8f@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 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 0 [ 42]: ACK sip:8344@10.10.119.251 SIP/2.0 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 1 [ 61]: Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-d9013913 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 2 [ 79]: From: 9971 ;tag=318bab21b44e20b7o2;ref=1000 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 3 [ 51]: To: ;tag=as6c6c1374 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 4 [ 41]: Call-ID: 4f9dc24-aad06b8f@10.10.119.248 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 5 [ 13]: CSeq: 101 ACK [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 7 [ 55]: Contact: 9971 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 8 [ 36]: User-Agent: Linksys/SPA9000-3.2.8(d) [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 9 [ 36]: Allow-Events: talk, hold, conference [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 10 [ 17]: Content-Length: 0 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 11 [ 0]: --- (11 headers 0 lines) --- [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:14624 handle_request: **** Received ACK (6) - Command in SIP ACK [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:2096 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #34 [Nov 20 22:33:02] DEBUG[2444]: chan_sip.c:2106 __sip_ack: Stopping retransmission on '4f9dc24-aad06b8f@10.10.119.248' of Response 101: Match Found centrala*CLI> centrala*CLI> centrala*CLI> centrala*CLI> centrala*CLI> <--- SIP read from 10.10.119.248:5060 ---> BYE sip:8344@10.10.119.251 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-8c74524b From: 9971 ;tag=318bab21b44e20b7o2;ref=1000 To: ;tag=as6c6c1374 Call-ID: 4f9dc24-aad06b8f@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 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 0 [ 42]: BYE sip:8344@10.10.119.251 SIP/2.0 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 1 [ 61]: Via: SIP/2.0/UDP 10.10.119.248:5060;branch=z9hG4bK-8c74524b [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 2 [ 79]: From: 9971 ;tag=318bab21b44e20b7o2;ref=1000 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 3 [ 51]: To: ;tag=as6c6c1374 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 4 [ 41]: Call-ID: 4f9dc24-aad06b8f@10.10.119.248 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 5 [ 13]: CSeq: 102 BYE [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 6 [ 16]: Max-Forwards: 70 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 7 [ 36]: User-Agent: Linksys/SPA9000-3.2.8(d) [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 8 [ 36]: Allow-Events: talk, hold, conference [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 9 [ 17]: Content-Length: 0 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 10 [ 0]: --- (10 headers 0 lines) --- [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:14624 handle_request: **** Received BYE (8) - Command in SIP BYE [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:14153 handle_request_bye: Initializing initreq for method BYE - callid 4f9dc24-aad06b8f@10.10.119.248 Sending to 10.10.119.248 : 5060 (no NAT) [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:14203 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-8c74524b;received=10.10.119.248 From: 9971 ;tag=318bab21b44e20b7o2;ref=1000 To: ;tag=as6c6c1374 Call-ID: 4f9dc24-aad06b8f@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 20 22:33:09] DEBUG[2483]: rtp.c:2815 bridge_native_loop: Oooh, got a hangup [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:16875 sip_set_rtp_peer: Sending reinvite on SIP '412f6751271edc7931c93b4437801a99@10.10.119.251' - It's audio soon redirected to IP 10.10.119.251 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:5662 reqprep: Strict routing enforced for session 412f6751271edc7931c93b4437801a99@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 20 22:33:09] DEBUG[2483]: chan_sip.c:6227 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:6228 add_sdp: ** Our prefcodec: 0x8 (alaw) Audio is at 10.10.119.251 port 14116 Adding codec 0x8 (alaw) to SDP [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:6357 add_sdp: -- Done with adding codecs to SDP [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:6401 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:1653 initialize_initreq: Initializing already initialized SIP dialog 412f6751271edc7931c93b4437801a99@10.10.119.251 (presumably reinvite) [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 0 [ 50]: INVITE sip:8344@10.10.119.225:5060 SIP/2.0 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK490b29dd;rport [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 2 [ 16]: Max-Forwards: 70 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 3 [ 64]: From: "9971" ;tag=as0ce8b33f [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 4 [ 53]: To: ;tag=A33E5334-A9F [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 5 [ 40]: Contact: [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 6 [ 57]: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 7 [ 16]: CSeq: 103 INVITE [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 8 [ 24]: User-Agent: Asterisk PBX [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 9 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 10 [ 19]: Supported: replaces [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 12 [ 29]: Content-Type: application/sdp [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 13 [ 19]: Content-Length: 188 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Header 14 [ 0]: [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 0 [ 3]: v=0 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 1 [ 39]: o=root 2483 2484 IN IP4 10.10.119.251 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 2 [ 9]: s=session [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 3 [ 24]: c=IN IP4 10.10.119.251 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 4 [ 5]: t=0 0 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 5 [ 23]: m=audio 14116 RTP/AVP 8 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 7 [ 25]: a=silenceSupp:off - - - - [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 8 [ 10]: a=ptime:20 [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:4636 parse_request: Body 9 [ 10]: a=sendrecv Reliably Transmitting (no NAT) to 10.10.119.225:5060: INVITE sip:8344@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK490b29dd;rport Max-Forwards: 70 From: "9971" ;tag=as0ce8b33f To: ;tag=A33E5334-A9F Contact: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 CSeq: 103 INVITE User-Agent: Asterisk PBX 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 2483 2484 IN IP4 10.10.119.251 s=session c=IN IP4 10.10.119.251 t=0 0 m=audio 14116 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:1997 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #35 [Nov 20 22:33:09] DEBUG[2483]: channel.c:3961 ast_channel_bridge: Returning from native bridge, channels: SIP/9971-081b1c08, SIP/10.10.119.225-081d01b0 [Nov 20 22:33:09] DEBUG[2483]: channel.c:1603 ast_hangup: Hanging up channel 'SIP/10.10.119.225-081d01b0' [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:3389 sip_hangup: Hangup call SIP/10.10.119.225-081d01b0, SIP callid 412f6751271edc7931c93b4437801a99@10.10.119.251) [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:3397 sip_hangup: update_call_counter(8344) - decrement call limit counter on hangup [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:3091 update_call_counter: Updating call counter for outgoing call Scheduling destruction of SIP dialog '412f6751271edc7931c93b4437801a99@10.10.119.251' in 32000 ms (Method: INVITE) [Nov 20 22:33:09] DEBUG[2483]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/10.10.119.225-081d01b0 [Nov 20 22:33:09] DEBUG[2425]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 10.10.119.225 [Nov 20 22:33:09] DEBUG[2425]: chan_sip.c:15222 sip_devicestate: Checking device state for peer 10.10.119.225 [Nov 20 22:33:09] DEBUG[2425]: devicestate.c:287 do_state_change: Changing state for SIP/10.10.119.225 - state 1 (Not in use) [Nov 20 22:33:09] DEBUG[2483]: rtp.c:1485 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Nov 20 22:33:09] DEBUG[2483]: app_dial.c:1668 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Nov 20 22:33:09] DEBUG[2483]: pbx.c:2281 __ast_pbx_run: Spawn extension (default,8344,1) exited non-zero on 'SIP/9971-081b1c08' == Spawn extension (default, 8344, 1) exited non-zero on 'SIP/9971-081b1c08' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is '"9971" <9971>' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is '9971' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is '8344' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is 'SIP/9971-081b1c08' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is 'SIP/10.10.119.225-081d01b0' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is 'SIP/10.10.119.225/8344|60|r' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is '2006-11-20 22:33:00' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is '2006-11-20 22:33:02' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is '2006-11-20 22:33:09' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is '9' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is '7' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is '' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is '1164058380.6' [Nov 20 22:33:09] DEBUG[2483]: pbx.c:1535 pbx_substitute_variables_helper_full: Function result is '' [Nov 20 22:33:09] DEBUG[2483]: channel.c:1603 ast_hangup: Hanging up channel 'SIP/9971-081b1c08' [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:3389 sip_hangup: Hangup call SIP/9971-081b1c08, SIP callid 4f9dc24-aad06b8f@10.10.119.248) [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:3397 sip_hangup: update_call_counter(9971) - decrement call limit counter on hangup [Nov 20 22:33:09] DEBUG[2483]: chan_sip.c:3091 update_call_counter: Updating call counter for incoming call [Nov 20 22:33:09] DEBUG[2483]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9971-081b1c08 [Nov 20 22:33:09] DEBUG[2487]: app_queue.c:568 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 20 22:33:09] DEBUG[2425]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9971 [Nov 20 22:33:09] DEBUG[2425]: chan_sip.c:15222 sip_devicestate: Checking device state for peer 9971 [Nov 20 22:33:09] DEBUG[2425]: devicestate.c:287 do_state_change: Changing state for SIP/9971 - state 1 (Not in use) [Nov 20 22:33:09] DEBUG[2488]: app_queue.c:568 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=z9hG4bK490b29dd;rport From: "9971" ;tag=as0ce8b33f To: ;tag=A33E5334-A9F Date: Mon, 20 Nov 2006 15:37:55 GMT Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 103 INVITE Allow-Events: telephone-event Content-Length: 0 <-------------> [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 0 [ 18]: SIP/2.0 100 Trying [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK490b29dd;rport [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 2 [ 64]: From: "9971" ;tag=as0ce8b33f [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 3 [ 53]: To: ;tag=A33E5334-A9F [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 4 [ 35]: Date: Mon, 20 Nov 2006 15:37:55 GMT [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 5 [ 57]: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 6 [ 33]: Server: Cisco-SIPGateway/IOS-12.x [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 7 [ 16]: CSeq: 103 INVITE [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 8 [ 29]: Allow-Events: telephone-event [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 9 [ 17]: Content-Length: 0 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 10 [ 0]: --- (10 headers 0 lines) --- [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:2140 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #35 - INVITE (got response) [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:2149 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '412f6751271edc7931c93b4437801a99@10.10.119.251' Request 103: Found [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:11708 handle_response_invite: SIP response 100 to standard invite [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:5662 reqprep: Strict routing enforced for session 412f6751271edc7931c93b4437801a99@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:8344@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56df4668;rport Max-Forwards: 70 From: "9971" ;tag=as0ce8b33f To: ;tag=A33E5334-A9F Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 CSeq: 104 BYE User-Agent: Asterisk PBX Content-Length: 0 --- [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:1997 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #37 Scheduling destruction of SIP dialog '412f6751271edc7931c93b4437801a99@10.10.119.251' in 32000 ms (Method: INVITE) Really destroying SIP dialog '4f9dc24-aad06b8f@10.10.119.248' Method: BYE 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=z9hG4bK490b29dd;rport From: "9971" ;tag=as0ce8b33f To: ;tag=A33E5334-A9F Date: Mon, 20 Nov 2006 15:37:55 GMT Call-ID: 412f6751271edc7931c93b4437801a99@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: 200 v=0 o=CiscoSystemsSIP-GW-UserAgent 5996 8501 IN IP4 10.10.119.225 s=SIP Call c=IN IP4 10.10.119.225 t=0 0 m=audio 17622 RTP/AVP 8 c=IN IP4 10.10.119.225 a=rtpmap:8 PCMA/8000 a=ptime:20 <-------------> [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 0 [ 14]: SIP/2.0 200 OK [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK490b29dd;rport [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 2 [ 64]: From: "9971" ;tag=as0ce8b33f [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 3 [ 53]: To: ;tag=A33E5334-A9F [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 4 [ 35]: Date: Mon, 20 Nov 2006 15:37:55 GMT [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 5 [ 57]: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 6 [ 33]: Server: Cisco-SIPGateway/IOS-12.x [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 7 [ 16]: CSeq: 103 INVITE [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 8 [ 97]: Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 9 [ 29]: Allow-Events: telephone-event [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 10 [ 46]: Contact: [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 11 [ 29]: Content-Type: application/sdp [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 12 [ 19]: Content-Length: 200 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 13 [ 0]: [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 0 [ 3]: v=0 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 1 [ 63]: o=CiscoSystemsSIP-GW-UserAgent 5996 8501 IN IP4 10.10.119.225 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 2 [ 10]: s=SIP Call [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 3 [ 24]: c=IN IP4 10.10.119.225 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 4 [ 5]: t=0 0 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 5 [ 23]: m=audio 17622 RTP/AVP 8 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 6 [ 24]: c=IN IP4 10.10.119.225 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Body 8 [ 10]: a=ptime:20 --- (13 headers 9 lines) --- [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:2091 __sip_ack: Acked pending invite 103 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:2106 __sip_ack: Stopping retransmission on '412f6751271edc7931c93b4437801a99@10.10.119.251' of Request 103: Match Found [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:11708 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4923 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.10.119.225:17622 Found description format PCMA for ID 8 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:5153 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0x508 (alaw|g729|ilbc), 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:17622 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:5230 process_sdp: We're settling with these formats: 0x8 (alaw) [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:3091 update_call_counter: Updating call counter for outgoing call --- set_address_from_contact host '10.10.119.225' [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:7892 build_route: build_route: Retaining previous route: [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:5662 reqprep: Strict routing enforced for session 412f6751271edc7931c93b4437801a99@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:8344@10.10.119.225:5060 SIP/2.0 Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK5ea58875;rport Max-Forwards: 70 From: "9971" ;tag=as0ce8b33f To: ;tag=A33E5334-A9F Contact: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 CSeq: 103 ACK User-Agent: Asterisk PBX 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=z9hG4bK56df4668;rport From: "9971" ;tag=as0ce8b33f To: ;tag=A33E5334-A9F Date: Mon, 20 Nov 2006 15:37:55 GMT Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 Server: Cisco-SIPGateway/IOS-12.x CSeq: 104 BYE Reason: Q.850;cause=16 Content-Length: 0 <-------------> [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 0 [ 14]: SIP/2.0 200 OK [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 10.10.119.251:5060;branch=z9hG4bK56df4668;rport [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 2 [ 64]: From: "9971" ;tag=as0ce8b33f [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 3 [ 53]: To: ;tag=A33E5334-A9F [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 4 [ 35]: Date: Mon, 20 Nov 2006 15:37:55 GMT [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 5 [ 57]: Call-ID: 412f6751271edc7931c93b4437801a99@10.10.119.251 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 6 [ 33]: Server: Cisco-SIPGateway/IOS-12.x [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 7 [ 13]: CSeq: 104 BYE [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 8 [ 22]: Reason: Q.850;cause=16 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 9 [ 17]: Content-Length: 0 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:4636 parse_request: Header 10 [ 0]: --- (10 headers 0 lines) --- [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:2096 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #37 [Nov 20 22:33:09] DEBUG[2444]: chan_sip.c:2106 __sip_ack: Stopping retransmission on '412f6751271edc7931c93b4437801a99@10.10.119.251' of Request 104: Match Found Really destroying SIP dialog '412f6751271edc7931c93b4437801a99@10.10.119.251' Method: INVITE centrala*CLI> centrala*CLI> centrala*CLI> centrala*CLI> sip show peer 9971 centrala*CLI> * Name : 9971 Secret : MD5Secret : Context : default Subscr.Cont. : Language : AMA flags : Unknown Transfer mode: open CallingPres : Presentation Allowed, Not Screened Callgroup : Pickupgroup : Mailbox : VM Extension : asterisk LastMsgsSent : 32767/65535 Call limit : 0 Dynamic : Yes Callerid : "" <> MaxCallBR : 384 kbps Expire : 2933 Insecure : no Nat : RFC3581 ACL : No T38 pt UDPTL : Yes CanReinvite : Yes PromiscRedir : No User=Phone : No Video Support: No Trust RPID : No Send RPID : No Subscriptions: Yes Overlap dial : Yes DTMFmode : info LastMsg : 0 ToHost : Addr->IP : 10.10.119.248 Port 5060 Defaddr->IP : 0.0.0.0 Port 5060 Def. Username: 9971 SIP Options : (none) Codecs : 0x108 (alaw|g729) Codec Order : (alaw:20,g729:20) Auto-Framing: No Status : Unmonitored Useragent : Reg. Contact : sip:9971@10.10.119.248:5060 centrala*CLI> sip show peer cisco3 centrala*CLI> * Name : cisco3 Secret : MD5Secret : Context : default Subscr.Cont. : Language : AMA flags : Unknown Transfer mode: open CallingPres : Presentation Allowed, Not Screened Callgroup : Pickupgroup : Mailbox : VM Extension : asterisk LastMsgsSent : 32767/65535 Call limit : 0 Dynamic : No Callerid : "" <> MaxCallBR : 384 kbps Expire : -1 Insecure : no Nat : RFC3581 ACL : No T38 pt UDPTL : Yes CanReinvite : Yes PromiscRedir : No User=Phone : No Video Support: No Trust RPID : No Send RPID : No Subscriptions: Yes Overlap dial : Yes DTMFmode : rfc2833 LastMsg : 0 ToHost : 10.10.119.225 Addr->IP : 10.10.119.225 Port 5060 Defaddr->IP : 0.0.0.0 Port 0 Def. Username: SIP Options : (none) Codecs : 0x108 (alaw|g729) Codec Order : (g729:20,alaw:20) Auto-Framing: No Status : Unmonitored Useragent : Reg. Contact : centrala*CLI> sip show settings centrala*CLI> Global Settings: ---------------- SIP Port: 5060 Bindaddress: 0.0.0.0 Videosupport: No AutoCreatePeer: No MatchAuthUsername: No Allow unknown access: Yes Allow subscriptions: Yes Allow overlap dialing: Yes Promsic. redir: No SIP domain support: No Call to non-local dom.: Yes URI user is phone no: No Our auth realm asterisk Realm. auth: No Always auth rejects: No Call limit peers only: No User Agent: Asterisk PBX MWI checking interval: 10 secs Reg. context: (not set) Caller ID: asterisk From: Domain: Record SIP history: Off Call Events: Off IP ToS SIP: CS0 IP ToS RTP audio: CS0 IP ToS RTP video: CS0 T38 fax pt UDPTL: Yes RFC2833 Compensation: No Jitterbuffer enabled: No Jitterbuffer forced: No Jitterbuffer max size: -1 Jitterbuffer resync: -1 Jitterbuffer impl: Jitterbuffer log: No SIP realtime: Disabled Global Signalling Settings: --------------------------- Codecs: g729:20,alaw:20,ilbc:30 T1 minimum: 100 Relax DTMF: No Compact SIP headers: No RTP Timeout: 0 (Disabled) RTP Hold Timeout: 0 (Disabled) MWI NOTIFY mime type: application/simple-message-summary DNS SRV lookup: No Pedantic SIP support: No Reg. min duration 60 secs Reg. max duration: 3600 secs Reg. default duration: 120 secs Outbound reg. timeout: 20 secs Outbound reg. attempts: 0 Notify ringing state: Yes Notify hold state: No SIP Transfer mode: open Max Call Bitrate: 384 kbps Auto-Framing: No Default Settings: ----------------- Context: default Nat: RFC3581 DTMF: rfc2833 Qualify: 0 Use ClientCode: No Progress inband: Never Language: (Defaults to English) MOH Interpret: default MOH Suggest: Voice Mail Extension: asterisk ---- centrala*CLI>