*CLI> [Dec 12 16:37:28] <--- SIP read from 192.168.71.235:49176 ---> INVITE sip:9105@192.168.71.2;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.71.235:5060;branch=z9hG4bK76168956 From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 To: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 Max-Forwards: 70 Date: Tue, 12 Dec 2006 GMT CSeq: 101 INVITE User-Agent: Cisco-CP7911G/8.0 Contact: Expires: 180 Accept: application/sdp Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Supported: replaces,join,norefersub Allow-Events: kpml,dialog Content-Length: 275 Content-Type: application/sdp Content-Disposition: session;handling=optional v=0 o=Cisco-SIPUA 941 0 IN IP4 192.168.71.235 s=SIP Call t=0 0 m=audio 21750 RTP/AVP 0 8 18 101 c=IN IP4 192.168.71.235 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/0 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: INVITE sip:9105@192.168.71.2;user=phone SIP/2.0 (47) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.235:5060;branch=z9hG4bK76168956 (59) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 (91) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: (38) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (59) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Max-Forwards: 70 (16) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: CSeq: 101 INVITE (16) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: User-Agent: Cisco-CP7911G/8.0 (29) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Contact: (53) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Expires: 180 (12) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Accept: application/sdp (23) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 13: Supported: replaces,join,norefersub (35) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 14: Allow-Events: kpml,dialog (25) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 15: Content-Length: 275 (19) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 16: Content-Type: application/sdp (29) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 17: Content-Disposition: session;handling=optional (46) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 18: (0) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: o=Cisco-SIPUA 941 0 IN IP4 192.168.71.235 (41) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: s=SIP Call (10) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: m=audio 21750 RTP/AVP 0 8 18 101 (32) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.235 (23) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:18 G729/0 (18) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=sendrecv (10) [Dec 12 16:37:28] --- (18 headers 13 lines) --- [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:2523 do_setnat: Setting NAT on RTP to Off [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4203 sip_alloc: Allocating new SIP dialog for 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 - INVITE (With RTP) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:14243 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:1636 parse_sip_options: Begin: parsing SIP "Supported: replaces,join,norefersub" [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:1644 parse_sip_options: Found SIP option: -replaces- [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:1650 parse_sip_options: Matched SIP option: replaces [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:1644 parse_sip_options: Found SIP option: -join- [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:1650 parse_sip_options: Matched SIP option: join [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:1644 parse_sip_options: Found SIP option: -norefersub- [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:1650 parse_sip_options: Matched SIP option: norefersub [Dec 12 16:37:28] Sending to 192.168.71.235 : 5060 (no NAT) [Dec 12 16:37:28] Using INVITE request as basis request - 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:2523 do_setnat: Setting NAT on RTP to Off [Dec 12 16:37:28] Found user '9065' [Dec 12 16:37:28] Found RTP audio format 0 [Dec 12 16:37:28] Found RTP audio format 8 [Dec 12 16:37:28] Found RTP audio format 18 [Dec 12 16:37:28] Found RTP audio format 101 [Dec 12 16:37:28] Peer audio RTP is at port 192.168.71.235:21750 [Dec 12 16:37:28] Found description format PCMU for ID 0 [Dec 12 16:37:28] Found description format PCMA for ID 8 [Dec 12 16:37:28] Found description format G729 for ID 18 [Dec 12 16:37:28] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:28] Found description format telephone-event for ID 101 [Dec 12 16:37:28] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4966 process_sdp: T38 state changed to 0 on channel [Dec 12 16:37:28] Capabilities: us - 0x4 (ulaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 12 16:37:28] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 12 16:37:28] Peer audio RTP is at port 192.168.71.235:21750 [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:5043 process_sdp: We're settling with these formats: 0x4 (ulaw) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:13054 handle_request_invite: Checking SIP call limits for device 9065 [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:2934 update_call_counter: Updating call counter for incoming call [Dec 12 16:37:28] Looking for 9105 in from-sip (domain 192.168.71.2) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:3699 sip_new: *** Our native formats are 0x4 (ulaw) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:3700 sip_new: *** Joint capabilities are 0x4 (ulaw) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:3701 sip_new: *** Our capabilities are 0x4 (ulaw) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:3702 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:3725 sip_new: This channel will not be able to handle video. [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:7784 build_route: build_route: Contact hop: [Dec 12 16:37:28] list_route: hop: [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:13128 handle_request_invite: SIP/9065-08201b70: New call is still down.... Trying... [Dec 12 16:37:28] <--- Transmitting (no NAT) to 192.168.71.235:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.71.235:5060;branch=z9hG4bK76168956;received=192.168.71.235 From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 To: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 12 16:37:28] DEBUG[14682]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9065-08201b70 [Dec 12 16:37:28] DEBUG[14677]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9065 [Dec 12 16:37:28] DEBUG[14677]: chan_sip.c:14828 sip_devicestate: Checking device state for peer 9065 [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1767 pbx_extension_helper: Launching 'Answer' [Dec 12 16:37:28] -- Executing [9105@from-sip:1] Answer("SIP/9065-08201b70", "") in new stack [Dec 12 16:37:28] DEBUG[14683]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9065-08201b70 [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:3381 sip_answer: SIP answering channel: SIP/9065-08201b70 [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:6255 transmit_response_with_sdp: Setting framing from config on incoming call [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:6003 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:6004 add_sdp: ** Our prefcodec: 0x0 (nothing) [Dec 12 16:37:28] Audio is at 192.168.71.2 port 8936 [Dec 12 16:37:28] Adding codec 0x4 (ulaw) to SDP [Dec 12 16:37:28] Adding non-codec 0x1 (telephone-event) to SDP [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:6155 add_sdp: -- Done with adding codecs to SDP [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:6200 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Dec 12 16:37:28] -- SIP Seeding peer from astdb: '9065' at 9065@192.168.71.235:5060 for 3600 [Dec 12 16:37:28] DEBUG[14677]: devicestate.c:287 do_state_change: Changing state for SIP/9065 - state 1 (Not in use) [Dec 12 16:37:28] DEBUG[14677]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9065 [Dec 12 16:37:28] DEBUG[14677]: chan_sip.c:14828 sip_devicestate: Checking device state for peer 9065 [Dec 12 16:37:28] DEBUG[14677]: devicestate.c:287 do_state_change: Changing state for SIP/9065 - state 1 (Not in use) [Dec 12 16:37:28] <--- Reliably Transmitting (no NAT) to 192.168.71.235:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.235:5060;branch=z9hG4bK76168956;received=192.168.71.235 From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 To: ;tag=as4c5be4da Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 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: 227 v=0 o=root 14683 14683 IN IP4 192.168.71.2 s=session c=IN IP4 192.168.71.2 t=0 0 m=audio 8936 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv <------------> [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #2 [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '9065' [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1767 pbx_extension_helper: Launching 'Set' [Dec 12 16:37:28] -- Executing [9105@from-sip:2] Set("SIP/9065-08201b70", "GROUP(sip-in-use)=9065") in new stack [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1767 pbx_extension_helper: Launching 'Goto' [Dec 12 16:37:28] -- Executing [9105@from-sip:3] Goto("SIP/9065-08201b70", "order-internal|9105|1") in new stack [Dec 12 16:37:28] -- Goto (order-internal,9105,1) [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1767 pbx_extension_helper: Launching 'Macro' [Dec 12 16:37:28] -- Executing [9105@order-internal:1] Macro("SIP/9065-08201b70", "sip-ext-dial|9105") in new stack [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1767 pbx_extension_helper: Launching 'Set' [Dec 12 16:37:28] -- Executing [s@macro-sip-ext-dial:1] Set("SIP/9065-08201b70", "ext=9105") in new stack [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '0' [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1688 pbx_substitute_variables_helper_full: Expression result is '0' [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1767 pbx_extension_helper: Launching 'GotoIf' [Dec 12 16:37:28] -- Executing [s@macro-sip-ext-dial:2] GotoIf("SIP/9065-08201b70", "0?3:6") in new stack [Dec 12 16:37:28] -- Goto (macro-sip-ext-dial,s,6) [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1767 pbx_extension_helper: Launching 'NoOp' [Dec 12 16:37:28] -- Executing [s@macro-sip-ext-dial:6] NoOp("SIP/9065-08201b70", ""Agent not in use"") in new stack [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1767 pbx_extension_helper: Launching 'Set' [Dec 12 16:37:28] -- Executing [s@macro-sip-ext-dial:7] Set("SIP/9065-08201b70", "OUTBOUND_GROUP=9105@sip-in-use") in new stack [Dec 12 16:37:28] DEBUG[14683]: pbx.c:1767 pbx_extension_helper: Launching 'Dial' [Dec 12 16:37:28] -- Executing [s@macro-sip-ext-dial:8] Dial("SIP/9065-08201b70", "SIP/9105|25") in new stack [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:14886 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4203 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Dec 12 16:37:28] DEBUG[14684]: app_queue.c:546 changethread: Device 'SIP/9065' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 12 16:37:28] DEBUG[14685]: app_queue.c:546 changethread: Device 'SIP/9065' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 12 16:37:28] -- SIP Seeding peer from astdb: '9105' at 9105@192.168.71.141:5060 for 3600 [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:2523 do_setnat: Setting NAT on RTP to Off [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:3699 sip_new: *** Our native formats are 0x4 (ulaw) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:3700 sip_new: *** Joint capabilities are 0x0 (nothing) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:3701 sip_new: *** Our capabilities are 0x4 (ulaw) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:3702 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:3704 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:3725 sip_new: This channel will not be able to handle video. [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4203 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) [Dec 12 16:37:28] Scheduling destruction of SIP dialog '61cd37a05dd00f785446bb7f5efd0b49@192.168.71.2' in 32000 ms (Method: NOTIFY) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: NOTIFY sip:9105@192.168.71.141:5060;transport=udp SIP/2.0 (57) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04f96a88;rport (63) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "asterisk" ;tag=as6feb5ed3 (59) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: (48) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Contact: (36) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Call-ID: 61cd37a05dd00f785446bb7f5efd0b49@192.168.71.2 (54) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 NOTIFY (16) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Event: message-summary (22) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Content-Type: application/simple-message-summary (48) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Content-Length: 88 (18) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: (0) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: Messages-Waiting: no (20) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: Message-Account: sip:8500@192.168.71.2 (38) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: Voice-Message: 0/0 (0/0) (24) [Dec 12 16:37:28] Reliably Transmitting (no NAT) to 192.168.71.141:5060: NOTIFY sip:9105@192.168.71.141:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04f96a88;rport From: "asterisk" ;tag=as6feb5ed3 To: Contact: Call-ID: 61cd37a05dd00f785446bb7f5efd0b49@192.168.71.2 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 88 Messages-Waiting: no Message-Account: sip:8500@192.168.71.2 Voice-Message: 0/0 (0/0) --- [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #5 [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:16449 sip_set_rtp_peer: Early remote bridge setting SIP '4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2' - Sending media to 192.168.71.235 [Dec 12 16:37:28] DEBUG[14683]: rtp.c:1518 ast_rtp_make_compatible: Seeded SDP of 'SIP/9105-0821e1d0' with that of 'SIP/9065-08201b70' [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-macro-sip-ext-dial-s-8. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable MACRO_DEPTH. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable OUTBOUND_GROUP. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-macro-sip-ext-dial-s-7. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-macro-sip-ext-dial-s-6. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-macro-sip-ext-dial-s-2. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable ext. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-macro-sip-ext-dial-s-1. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable ARG1. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable MACRO_PRIORITY. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable MACRO_CONTEXT. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable MACRO_EXTEN. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-order-internal-9105-1. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-from-sip-9105-3. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable GROUP_sip-in-use. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-from-sip-9105-2. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-from-sip-9105-1. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Dec 12 16:37:28] DEBUG[14683]: channel.c:3145 ast_channel_inherit_variables: Not copying variable SIPURI. [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:2774 sip_call: Outgoing Call for 9105 [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:2934 update_call_counter: Updating call counter for outgoing call [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:2782 sip_call: Our T38 capability (0), joint T38 capability (0) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:6003 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: False [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:6004 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Dec 12 16:37:28] Audio is at 192.168.71.2 port 13730 [Dec 12 16:37:28] Adding codec 0x4 (ulaw) to SDP [Dec 12 16:37:28] Adding non-codec 0x1 (telephone-event) to SDP [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:6155 add_sdp: -- Done with adding codecs to SDP [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:6200 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 0: INVITE sip:9105@192.168.71.141:5060;transport=udp SIP/2.0 (57) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK55cd018a;rport (63) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 2: From: "Jean-Francois Stenuit" ;tag=as6f57693e (68) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 3: To: (48) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 4: Contact: (32) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 5: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 (54) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 9: Date: Tue, 12 Dec 2006 15:37:28 GMT (35) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 11: Supported: replaces (19) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 12: Content-Type: application/sdp (29) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 13: Content-Length: 232 (19) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 14: (0) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: o=root 14683 14683 IN IP4 192.168.71.235 (40) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: s=session (9) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.235 (23) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: m=audio 21750 RTP/AVP 0 101 (27) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=sendrecv (10) [Dec 12 16:37:28] Reliably Transmitting (no NAT) to 192.168.71.141:5060: INVITE sip:9105@192.168.71.141:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK55cd018a;rport From: "Jean-Francois Stenuit" ;tag=as6f57693e To: Contact: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Tue, 12 Dec 2006 15:37:28 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 232 v=0 o=root 14683 14683 IN IP4 192.168.71.235 s=session c=IN IP4 192.168.71.235 t=0 0 m=audio 21750 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- [Dec 12 16:37:28] DEBUG[14683]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #6 [Dec 12 16:37:28] -- Called 9105 [Dec 12 16:37:28] <--- SIP read from 192.168.71.235:49176 ---> ACK sip:9105@192.168.71.2:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.71.235:5060;branch=z9hG4bKae57eedf From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 To: ;tag=as4c5be4da Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 Max-Forwards: 70 Date: Tue, 12 Dec 2006 GMT CSeq: 101 ACK User-Agent: Cisco-CP7911G/8.0 Content-Length: 0 <-------------> [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: ACK sip:9105@192.168.71.2:5060 SIP/2.0 (38) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.235:5060;branch=z9hG4bKae57eedf (59) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 (91) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=as4c5be4da (53) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (59) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Max-Forwards: 70 (16) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: CSeq: 101 ACK (13) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: User-Agent: Cisco-CP7911G/8.0 (29) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Content-Length: 0 (17) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: (0) [Dec 12 16:37:28] --- (10 headers 0 lines) --- [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:14243 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:2026 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2 [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235' of Response 101: Match Not Found [Dec 12 16:37:28] <--- SIP read from 192.168.71.141:49174 ---> SIP/2.0 400 Bad Request Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04f96a88;rport From: "asterisk" ;tag=as6feb5ed3 To: Call-ID: 61cd37a05dd00f785446bb7f5efd0b49@192.168.71.2 Date: Tue, 12 Dec 2006 GMT Warning: 399 Bad MWI NOTIFY CSeq: 102 NOTIFY Content-Length: 0 <-------------> [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 400 Bad Request (23) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04f96a88;rport (63) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "asterisk" ;tag=as6feb5ed3 (59) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: (48) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 61cd37a05dd00f785446bb7f5efd0b49@192.168.71.2 (54) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: Warning: 399 Bad MWI NOTIFY (27) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: CSeq: 102 NOTIFY (16) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Content-Length: 0 (17) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: (0) [Dec 12 16:37:28] --- (9 headers 0 lines) --- [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:2026 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5 [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '61cd37a05dd00f785446bb7f5efd0b49@192.168.71.2' of Request 102: Match Not Found [Dec 12 16:37:28] -- Got SIP response 400 "Bad Request" back from 192.168.71.141 [Dec 12 16:37:28] Really destroying SIP dialog '61cd37a05dd00f785446bb7f5efd0b49@192.168.71.2' Method: NOTIFY [Dec 12 16:37:28] <--- SIP read from 192.168.71.141:49166 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK55cd018a;rport From: "Jean-Francois Stenuit" ;tag=as6f57693e To: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 Date: Tue, 12 Dec 2006 GMT CSeq: 102 INVITE Server: Cisco-CP7911G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Allow-Events: kpml,dialog Content-Length: 0 <-------------> [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 100 Trying (18) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK55cd018a;rport (63) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Jean-Francois Stenuit" ;tag=as6f57693e (68) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: (48) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 (54) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Contact: (53) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Allow-Events: kpml,dialog (25) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Content-Length: 0 (17) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: (0) [Dec 12 16:37:28] --- (12 headers 0 lines) --- [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:2069 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #6 - INVITE (got response) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:2078 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2' Request 102: Found [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:11385 handle_response_invite: SIP response 100 to standard invite [Dec 12 16:37:28] <--- SIP read from 192.168.71.141:49166 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK55cd018a;rport From: "Jean-Francois Stenuit" ;tag=as6f57693e To: ;tag=0019068bf14b000de0707056-fa25b367 Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 Date: Tue, 12 Dec 2006 GMT CSeq: 102 INVITE Server: Cisco-CP7911G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Allow-Events: kpml,dialog Content-Length: 0 <-------------> [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK55cd018a;rport (63) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Jean-Francois Stenuit" ;tag=as6f57693e (68) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=0019068bf14b000de0707056-fa25b367 (86) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 (54) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Contact: (53) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Allow-Events: kpml,dialog (25) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Content-Length: 0 (17) [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: (0) [Dec 12 16:37:28] --- (12 headers 0 lines) --- [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:2078 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2' Request 102: Found [Dec 12 16:37:28] DEBUG[14682]: chan_sip.c:11385 handle_response_invite: SIP response 180 to standard invite [Dec 12 16:37:28] DEBUG[14682]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9105-0821e1d0 [Dec 12 16:37:28] -- SIP/9105-0821e1d0 is ringing [Dec 12 16:37:28] DEBUG[14683]: rtp.c:1453 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/9065-08201b70' with that of 'SIP/9105-0821e1d0' [Dec 12 16:37:28] DEBUG[14683]: channel.c:2279 ast_indicate_data: Driver for channel 'SIP/9065-08201b70' does not support indication 3, emulating it [Dec 12 16:37:28] DEBUG[14683]: channel.c:2680 set_format: Set channel SIP/9065-08201b70 to write format slin [Dec 12 16:37:28] DEBUG[14683]: channel.c:1860 ast_settimeout: Scheduling timer at 160 sample intervals [Dec 12 16:37:28] DEBUG[14677]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9105 [Dec 12 16:37:28] DEBUG[14677]: chan_sip.c:14828 sip_devicestate: Checking device state for peer 9105 [Dec 12 16:37:28] DEBUG[14677]: devicestate.c:287 do_state_change: Changing state for SIP/9105 - state 1 (Not in use) [Dec 12 16:37:28] DEBUG[14686]: app_queue.c:546 changethread: Device 'SIP/9105' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 12 16:37:28] DEBUG[14683]: channel.c:2177 __ast_read: Generator got voice, switching to phase locked mode [Dec 12 16:37:28] DEBUG[14683]: channel.c:1860 ast_settimeout: Scheduling timer at 0 sample intervals [Dec 12 16:37:28] DEBUG[14683]: rtp.c:2555 ast_rtp_write: Ooh, format changed from unknown to ulaw [Dec 12 16:37:28] DEBUG[14683]: rtp.c:2572 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160 [Dec 12 16:37:31] <--- SIP read from 192.168.71.141:49166 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK55cd018a;rport From: "Jean-Francois Stenuit" ;tag=as6f57693e To: ;tag=0019068bf14b000de0707056-fa25b367 Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 Date: Tue, 12 Dec 2006 GMT CSeq: 102 INVITE Server: Cisco-CP7911G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Supported: replaces,join,norefersub Allow-Events: kpml,dialog Content-Length: 208 Content-Type: application/sdp Content-Disposition: session;handling=optional v=0 o=Cisco-SIPUA 9472 0 IN IP4 192.168.71.141 s=SIP Call t=0 0 m=audio 32212 RTP/AVP 0 101 c=IN IP4 192.168.71.141 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK55cd018a;rport (63) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Jean-Francois Stenuit" ;tag=as6f57693e (68) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=0019068bf14b000de0707056-fa25b367 (86) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 (54) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Contact: (53) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Supported: replaces,join,norefersub (35) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Allow-Events: kpml,dialog (25) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: Content-Length: 208 (19) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 13: Content-Type: application/sdp (29) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 14: Content-Disposition: session;handling=optional (46) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 15: (0) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: o=Cisco-SIPUA 9472 0 IN IP4 192.168.71.141 (42) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: s=SIP Call (10) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: m=audio 32212 RTP/AVP 0 101 (27) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.141 (23) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=sendrecv (10) [Dec 12 16:37:31] --- (15 headers 10 lines) --- [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:2018 __sip_ack: Acked pending invite 102 [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2' of Request 102: Match Not Found [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:11385 handle_response_invite: SIP response 200 to standard invite [Dec 12 16:37:31] Found RTP audio format 0 [Dec 12 16:37:31] Found RTP audio format 101 [Dec 12 16:37:31] Peer audio RTP is at port 192.168.71.141:32212 [Dec 12 16:37:31] Found description format PCMU for ID 0 [Dec 12 16:37:31] Found description format telephone-event for ID 101 [Dec 12 16:37:31] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:4966 process_sdp: T38 state changed to 0 on channel SIP/9105-0821e1d0 [Dec 12 16:37:31] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 12 16:37:31] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 12 16:37:31] Peer audio RTP is at port 192.168.71.141:32212 [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:5043 process_sdp: We're settling with these formats: 0x4 (ulaw) [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:5050 process_sdp: We have an owner, now see if we need to change this call [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:2934 update_call_counter: Updating call counter for outgoing call [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:7784 build_route: build_route: Contact hop: [Dec 12 16:37:31] list_route: hop: [Dec 12 16:37:31] DEBUG[14682]: chan_sip.c:5474 reqprep: Strict routing enforced for session 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 [Dec 12 16:37:31] set_destination: Parsing for address/port to send to [Dec 12 16:37:31] set_destination: set destination to 192.168.71.141, port 5060 [Dec 12 16:37:31] Transmitting (no NAT) to 192.168.71.141:5060: ACK sip:9105@192.168.71.141:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK7926915c;rport From: "Jean-Francois Stenuit" ;tag=as6f57693e To: ;tag=0019068bf14b000de0707056-fa25b367 Contact: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 12 16:37:31] DEBUG[14683]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9105-0821e1d0 [Dec 12 16:37:31] -- SIP/9105-0821e1d0 answered SIP/9065-08201b70 [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:16452 sip_set_rtp_peer: Sending reinvite on SIP '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235' - It's audio soon redirected to IP 192.168.71.141 [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:5474 reqprep: Strict routing enforced for session 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:31] set_destination: Parsing for address/port to send to [Dec 12 16:37:31] set_destination: set destination to 192.168.71.235, port 5060 [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:6003 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:6004 add_sdp: ** Our prefcodec: 0x0 (nothing) [Dec 12 16:37:31] Audio is at 192.168.71.2 port 8936 [Dec 12 16:37:31] Adding codec 0x4 (ulaw) to SDP [Dec 12 16:37:31] Adding non-codec 0x1 (telephone-event) to SDP [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:6155 add_sdp: -- Done with adding codecs to SDP [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:6200 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:1585 initialize_initreq: Initializing already initialized SIP dialog 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (presumably reinvite) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 0: INVITE sip:9065@192.168.71.235:5060;transport=udp SIP/2.0 (57) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK34975cb8;rport (63) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 2: From: ;tag=as4c5be4da (55) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 3: To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 (89) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 4: Contact: (32) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 5: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (59) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 10: Supported: replaces (19) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 12: Content-Type: application/sdp (29) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 13: Content-Length: 232 (19) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 14: (0) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: o=root 14683 14684 IN IP4 192.168.71.141 (40) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: s=session (9) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.141 (23) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: m=audio 32212 RTP/AVP 0 101 (27) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=sendrecv (10) [Dec 12 16:37:31] Reliably Transmitting (no NAT) to 192.168.71.235:5060: INVITE sip:9065@192.168.71.235:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK34975cb8;rport From: ;tag=as4c5be4da To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 Contact: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 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 (External RTP bridge) Content-Type: application/sdp Content-Length: 232 v=0 o=root 14683 14684 IN IP4 192.168.71.141 s=session c=IN IP4 192.168.71.141 t=0 0 m=audio 32212 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- [Dec 12 16:37:31] DEBUG[14683]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #9 [Dec 12 16:37:31] DEBUG[14683]: rtp.c:1453 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/9065-08201b70' with that of 'SIP/9105-0821e1d0' [Dec 12 16:37:31] DEBUG[14683]: channel.c:2680 set_format: Set channel SIP/9065-08201b70 to write format ulaw [Dec 12 16:37:31] DEBUG[14683]: channel.c:1860 ast_settimeout: Scheduling timer at 0 sample intervals [Dec 12 16:37:31] -- Native bridging SIP/9065-08201b70 and SIP/9105-0821e1d0 [Dec 12 16:37:31] DEBUG[14677]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9105 [Dec 12 16:37:31] DEBUG[14677]: chan_sip.c:14828 sip_devicestate: Checking device state for peer 9105 [Dec 12 16:37:31] DEBUG[14677]: devicestate.c:287 do_state_change: Changing state for SIP/9105 - state 1 (Not in use) [Dec 12 16:37:31] DEBUG[14687]: app_queue.c:546 changethread: Device 'SIP/9105' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 12 16:37:31] DEBUG[14683]: rtp.c:2555 ast_rtp_write: Ooh, format changed from unknown to ulaw [Dec 12 16:37:31] DEBUG[14683]: rtp.c:2572 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160 [Dec 12 16:37:32] <--- SIP read from 192.168.71.235:49176 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK34975cb8;rport From: ;tag=as4c5be4da To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 Date: Tue, 12 Dec 2006 GMT CSeq: 102 INVITE Server: Cisco-CP7911G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Supported: replaces,join,norefersub Allow-Events: kpml,dialog Content-Length: 207 Content-Type: application/sdp Content-Disposition: session;handling=optional v=0 o=Cisco-SIPUA 941 1 IN IP4 192.168.71.235 s=SIP Call t=0 0 m=audio 21750 RTP/AVP 0 101 c=IN IP4 192.168.71.235 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK34975cb8;rport (63) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: ;tag=as4c5be4da (55) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 (89) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (59) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Contact: (53) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Supported: replaces,join,norefersub (35) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Allow-Events: kpml,dialog (25) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: Content-Length: 207 (19) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 13: Content-Type: application/sdp (29) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 14: Content-Disposition: session;handling=optional (46) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 15: (0) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: o=Cisco-SIPUA 941 1 IN IP4 192.168.71.235 (41) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: s=SIP Call (10) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: m=audio 21750 RTP/AVP 0 101 (27) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.235 (23) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=sendrecv (10) [Dec 12 16:37:32] --- (15 headers 10 lines) --- [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:2018 __sip_ack: Acked pending invite 102 [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:2026 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #9 [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235' of Request 102: Match Not Found [Dec 12 16:37:32] SIP Response message for INCOMING dialog INVITE arrived [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:11383 handle_response_invite: SIP response 200 to RE-invite on incoming call 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:32] Found RTP audio format 0 [Dec 12 16:37:32] Found RTP audio format 101 [Dec 12 16:37:32] Peer audio RTP is at port 192.168.71.235:21750 [Dec 12 16:37:32] Found description format PCMU for ID 0 [Dec 12 16:37:32] Found description format telephone-event for ID 101 [Dec 12 16:37:32] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:4966 process_sdp: T38 state changed to 0 on channel SIP/9065-08201b70 [Dec 12 16:37:32] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 12 16:37:32] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 12 16:37:32] Peer audio RTP is at port 192.168.71.235:21750 [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:5043 process_sdp: We're settling with these formats: 0x4 (ulaw) [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:5050 process_sdp: We have an owner, now see if we need to change this call [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:11503 handle_response_invite: Strange... The other side of the bridge does not have a udptl struct [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:11508 handle_response_invite: T38 state changed to 0 on channel SIP [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:11511 handle_response_invite: T38 state changed to 0 on channel SIP/9065-08201b70 [Dec 12 16:37:32] DEBUG[14682]: chan_sip.c:5474 reqprep: Strict routing enforced for session 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:32] set_destination: Parsing for address/port to send to [Dec 12 16:37:32] set_destination: set destination to 192.168.71.235, port 5060 [Dec 12 16:37:32] Transmitting (no NAT) to 192.168.71.235:5060: ACK sip:9065@192.168.71.235:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK2e3360af;rport From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 To: ;tag=as4c5be4da Contact: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 12 16:37:33] <--- SIP read from 192.168.71.235:49176 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK34975cb8;rport From: ;tag=as4c5be4da To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 Date: Tue, 12 Dec 2006 GMT CSeq: 102 INVITE Server: Cisco-CP7911G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Supported: replaces,join,norefersub Allow-Events: kpml,dialog Content-Length: 207 Content-Type: application/sdp Content-Disposition: session;handling=optional v=0 o=Cisco-SIPUA 941 1 IN IP4 192.168.71.235 s=SIP Call t=0 0 m=audio 21750 RTP/AVP 0 101 c=IN IP4 192.168.71.235 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK34975cb8;rport (63) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: ;tag=as4c5be4da (55) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 (89) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (59) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Contact: (53) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Supported: replaces,join,norefersub (35) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Allow-Events: kpml,dialog (25) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: Content-Length: 207 (19) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 13: Content-Type: application/sdp (29) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 14: Content-Disposition: session;handling=optional (46) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 15: (0) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: o=Cisco-SIPUA 941 1 IN IP4 192.168.71.235 (41) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: s=SIP Call (10) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: m=audio 21750 RTP/AVP 0 101 (27) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.235 (23) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=sendrecv (10) [Dec 12 16:37:33] --- (15 headers 10 lines) --- [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235' of Request 102: Match Found [Dec 12 16:37:33] SIP Response message for INCOMING dialog INVITE arrived [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:11383 handle_response_invite: SIP response 200 to RE-invite on incoming call 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:33] Found RTP audio format 0 [Dec 12 16:37:33] Found RTP audio format 101 [Dec 12 16:37:33] Peer audio RTP is at port 192.168.71.235:21750 [Dec 12 16:37:33] Found description format PCMU for ID 0 [Dec 12 16:37:33] Found description format telephone-event for ID 101 [Dec 12 16:37:33] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:4966 process_sdp: T38 state changed to 0 on channel SIP/9065-08201b70 [Dec 12 16:37:33] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 12 16:37:33] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 12 16:37:33] Peer audio RTP is at port 192.168.71.235:21750 [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:5043 process_sdp: We're settling with these formats: 0x4 (ulaw) [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:5050 process_sdp: We have an owner, now see if we need to change this call [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:11503 handle_response_invite: Strange... The other side of the bridge does not have a udptl struct [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:11508 handle_response_invite: T38 state changed to 0 on channel SIP [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:11511 handle_response_invite: T38 state changed to 0 on channel SIP/9065-08201b70 [Dec 12 16:37:33] DEBUG[14682]: chan_sip.c:5474 reqprep: Strict routing enforced for session 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:33] set_destination: Parsing for address/port to send to [Dec 12 16:37:33] set_destination: set destination to 192.168.71.235, port 5060 [Dec 12 16:37:33] Transmitting (no NAT) to 192.168.71.235:5060: ACK sip:9065@192.168.71.235:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK4748baa2;rport From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 To: ;tag=as4c5be4da Contact: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 12 16:37:35] <--- SIP read from 192.168.71.235:49176 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK34975cb8;rport From: ;tag=as4c5be4da To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 Date: Tue, 12 Dec 2006 GMT CSeq: 102 INVITE Server: Cisco-CP7911G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Supported: replaces,join,norefersub Allow-Events: kpml,dialog Content-Length: 207 Content-Type: application/sdp Content-Disposition: session;handling=optional v=0 o=Cisco-SIPUA 941 1 IN IP4 192.168.71.235 s=SIP Call t=0 0 m=audio 21750 RTP/AVP 0 101 c=IN IP4 192.168.71.235 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK34975cb8;rport (63) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: ;tag=as4c5be4da (55) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 (89) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (59) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Contact: (53) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Supported: replaces,join,norefersub (35) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Allow-Events: kpml,dialog (25) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: Content-Length: 207 (19) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 13: Content-Type: application/sdp (29) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 14: Content-Disposition: session;handling=optional (46) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 15: (0) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: o=Cisco-SIPUA 941 1 IN IP4 192.168.71.235 (41) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: s=SIP Call (10) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: m=audio 21750 RTP/AVP 0 101 (27) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.235 (23) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=sendrecv (10) [Dec 12 16:37:35] --- (15 headers 10 lines) --- [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235' of Request 102: Match Found [Dec 12 16:37:35] SIP Response message for INCOMING dialog INVITE arrived [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:11383 handle_response_invite: SIP response 200 to RE-invite on incoming call 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:35] Found RTP audio format 0 [Dec 12 16:37:35] Found RTP audio format 101 [Dec 12 16:37:35] Peer audio RTP is at port 192.168.71.235:21750 [Dec 12 16:37:35] Found description format PCMU for ID 0 [Dec 12 16:37:35] Found description format telephone-event for ID 101 [Dec 12 16:37:35] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4966 process_sdp: T38 state changed to 0 on channel SIP/9065-08201b70 [Dec 12 16:37:35] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 12 16:37:35] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 12 16:37:35] Peer audio RTP is at port 192.168.71.235:21750 [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:5043 process_sdp: We're settling with these formats: 0x4 (ulaw) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:5050 process_sdp: We have an owner, now see if we need to change this call [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:11503 handle_response_invite: Strange... The other side of the bridge does not have a udptl struct [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:11508 handle_response_invite: T38 state changed to 0 on channel SIP [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:11511 handle_response_invite: T38 state changed to 0 on channel SIP/9065-08201b70 [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:5474 reqprep: Strict routing enforced for session 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:35] set_destination: Parsing for address/port to send to [Dec 12 16:37:35] set_destination: set destination to 192.168.71.235, port 5060 [Dec 12 16:37:35] Transmitting (no NAT) to 192.168.71.235:5060: ACK sip:9065@192.168.71.235:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK5ea70c80;rport From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 To: ;tag=as4c5be4da Contact: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 12 16:37:35] <--- SIP read from 192.168.71.141:49166 ---> INVITE sip:9065@192.168.71.2:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK78922c8e From: ;tag=0019068bf14b000de0707056-fa25b367 To: "Jean-Francois Stenuit" ;tag=as6f57693e Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 Max-Forwards: 70 Date: Tue, 12 Dec 2006 GMT CSeq: 101 INVITE User-Agent: Cisco-CP7911G/8.0 Contact: Accept: application/sdp Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Supported: replaces,join,norefersub Allow-Events: kpml,dialog Content-Length: 276 Content-Type: application/sdp Content-Disposition: session;handling=optional v=0 o=Cisco-SIPUA 9472 1 IN IP4 192.168.71.141 s=SIP Call t=0 0 m=audio 32212 RTP/AVP 0 8 18 101 c=IN IP4 192.168.71.141 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/0 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendonly <-------------> [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: INVITE sip:9065@192.168.71.2:5060 SIP/2.0 (41) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK78922c8e (59) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: ;tag=0019068bf14b000de0707056-fa25b367 (88) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: "Jean-Francois Stenuit" ;tag=as6f57693e (66) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 (54) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Max-Forwards: 70 (16) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: CSeq: 101 INVITE (16) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: User-Agent: Cisco-CP7911G/8.0 (29) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Contact: (53) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Accept: application/sdp (23) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: Supported: replaces,join,norefersub (35) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 13: Allow-Events: kpml,dialog (25) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 14: Content-Length: 276 (19) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 15: Content-Type: application/sdp (29) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 16: Content-Disposition: session;handling=optional (46) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 17: (0) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: o=Cisco-SIPUA 9472 1 IN IP4 192.168.71.141 (42) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: s=SIP Call (10) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: m=audio 32212 RTP/AVP 0 8 18 101 (32) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.141 (23) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:18 G729/0 (18) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=sendonly (10) [Dec 12 16:37:35] --- (17 headers 13 lines) --- [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:14243 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:1636 parse_sip_options: Begin: parsing SIP "Supported: replaces,join,norefersub" [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:1644 parse_sip_options: Found SIP option: -replaces- [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:1650 parse_sip_options: Matched SIP option: replaces [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:1644 parse_sip_options: Found SIP option: -join- [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:1650 parse_sip_options: Matched SIP option: join [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:1644 parse_sip_options: Found SIP option: -norefersub- [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:1650 parse_sip_options: Matched SIP option: norefersub [Dec 12 16:37:35] Sending to 192.168.71.141 : 5060 (no NAT) [Dec 12 16:37:35] Found RTP audio format 0 [Dec 12 16:37:35] Found RTP audio format 8 [Dec 12 16:37:35] Found RTP audio format 18 [Dec 12 16:37:35] Found RTP audio format 101 [Dec 12 16:37:35] Peer audio RTP is at port 192.168.71.141:32212 [Dec 12 16:37:35] Found description format PCMU for ID 0 [Dec 12 16:37:35] Found description format PCMA for ID 8 [Dec 12 16:37:35] Found description format G729 for ID 18 [Dec 12 16:37:35] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:35] Found description format telephone-event for ID 101 [Dec 12 16:37:35] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4966 process_sdp: T38 state changed to 0 on channel SIP/9105-0821e1d0 [Dec 12 16:37:35] Capabilities: us - 0x4 (ulaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 12 16:37:35] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 12 16:37:35] Peer audio RTP is at port 192.168.71.141:32212 [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:5043 process_sdp: We're settling with these formats: 0x4 (ulaw) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:5050 process_sdp: We have an owner, now see if we need to change this call [Dec 12 16:37:35] DEBUG[14682]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9105 [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:13106 handle_request_invite: Got a SIP re-invite for call 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:13195 handle_request_invite: SIP/9105-0821e1d0: This call is UP.... [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:6003 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:6004 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Dec 12 16:37:35] Audio is at 192.168.71.2 port 13730 [Dec 12 16:37:35] Adding codec 0x4 (ulaw) to SDP [Dec 12 16:37:35] Adding non-codec 0x1 (telephone-event) to SDP [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:6155 add_sdp: -- Done with adding codecs to SDP [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:6200 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Dec 12 16:37:35] <--- Reliably Transmitting (no NAT) to 192.168.71.141:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK78922c8e;received=192.168.71.141 From: ;tag=0019068bf14b000de0707056-fa25b367 To: "Jean-Francois Stenuit" ;tag=as6f57693e Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 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: 232 v=0 o=root 14683 14684 IN IP4 192.168.71.235 s=session c=IN IP4 192.168.71.235 t=0 0 m=audio 21750 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly <------------> [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #11 [Dec 12 16:37:35] -- Started music on hold, class 'default', on SIP/9065-08201b70 [Dec 12 16:37:35] DEBUG[14683]: channel.c:1860 ast_settimeout: Scheduling timer at 160 sample intervals [Dec 12 16:37:35] DEBUG[14683]: rtp.c:2689 bridge_native_loop: Oooh, 'SIP/9105-0821e1d0' changed end address to 0.0.0.0:0 (format 268) [Dec 12 16:37:35] DEBUG[14683]: rtp.c:2691 bridge_native_loop: Oooh, 'SIP/9105-0821e1d0' changed end vaddress to 0.0.0.0:0 (format 268) [Dec 12 16:37:35] DEBUG[14683]: rtp.c:2693 bridge_native_loop: Oooh, 'SIP/9105-0821e1d0' was 192.168.71.141:32212/(format 4) [Dec 12 16:37:35] DEBUG[14683]: rtp.c:2695 bridge_native_loop: Oooh, 'SIP/9105-0821e1d0' was 0.0.0.0:0/(format 4) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:16452 sip_set_rtp_peer: Sending reinvite on SIP '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235' - It's audio soon redirected to IP 192.168.71.2 [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:5474 reqprep: Strict routing enforced for session 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:35] set_destination: Parsing for address/port to send to [Dec 12 16:37:35] set_destination: set destination to 192.168.71.235, port 5060 [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:6003 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:6004 add_sdp: ** Our prefcodec: 0x0 (nothing) [Dec 12 16:37:35] Audio is at 192.168.71.2 port 8936 [Dec 12 16:37:35] Adding codec 0x4 (ulaw) to SDP [Dec 12 16:37:35] Adding non-codec 0x1 (telephone-event) to SDP [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:6155 add_sdp: -- Done with adding codecs to SDP [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:6200 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:1585 initialize_initreq: Initializing already initialized SIP dialog 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (presumably reinvite) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 0: INVITE sip:9065@192.168.71.235:5060;transport=udp SIP/2.0 (57) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK35b33d95;rport (63) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 2: From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 (91) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=as4c5be4da (53) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 4: Contact: (32) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 5: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (59) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 6: CSeq: 103 INVITE (16) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 10: Supported: replaces (19) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 12: Content-Type: application/sdp (29) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 13: Content-Length: 227 (19) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 14: (0) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: o=root 14683 14685 IN IP4 192.168.71.2 (38) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: s=session (9) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.2 (21) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: m=audio 8936 RTP/AVP 0 101 (26) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=sendrecv (10) [Dec 12 16:37:35] Reliably Transmitting (no NAT) to 192.168.71.235:5060: INVITE sip:9065@192.168.71.235:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK35b33d95;rport From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 To: ;tag=as4c5be4da Contact: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 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: 227 v=0 o=root 14683 14685 IN IP4 192.168.71.2 s=session c=IN IP4 192.168.71.2 t=0 0 m=audio 8936 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- [Dec 12 16:37:35] DEBUG[14683]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #12 [Dec 12 16:37:35] DEBUG[14677]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9105 [Dec 12 16:37:35] DEBUG[14677]: chan_sip.c:14828 sip_devicestate: Checking device state for peer 9105 [Dec 12 16:37:35] DEBUG[14677]: devicestate.c:287 do_state_change: Changing state for SIP/9105 - state 8 (On Hold) [Dec 12 16:37:35] DEBUG[14688]: app_queue.c:546 changethread: Device 'SIP/9105' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. [Dec 12 16:37:35] <--- SIP read from 192.168.71.141:49166 ---> ACK sip:9065@192.168.71.2:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK2af961df From: ;tag=0019068bf14b000de0707056-fa25b367 To: "Jean-Francois Stenuit" ;tag=as6f57693e Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 Max-Forwards: 70 Date: Tue, 12 Dec 2006 GMT CSeq: 101 ACK User-Agent: Cisco-CP7911G/8.0 Content-Length: 0 <-------------> [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: ACK sip:9065@192.168.71.2:5060 SIP/2.0 (38) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK2af961df (59) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: ;tag=0019068bf14b000de0707056-fa25b367 (88) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: "Jean-Francois Stenuit" ;tag=as6f57693e (66) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 (54) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Max-Forwards: 70 (16) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: CSeq: 101 ACK (13) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: User-Agent: Cisco-CP7911G/8.0 (29) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Content-Length: 0 (17) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: (0) [Dec 12 16:37:35] --- (10 headers 0 lines) --- [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:14243 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:2026 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #11 [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2' of Response 101: Match Not Found [Dec 12 16:37:35] <--- SIP read from 192.168.71.235:49184 ---> SIP/2.0 481 Call Leg/Transaction Does Not Exist Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK35b33d95;rport From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 To: ;tag=as4c5be4da Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 Date: Tue, 12 Dec 2006 GMT CSeq: 103 INVITE Content-Length: 0 <-------------> [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 481 Call Leg/Transaction Does Not Exist (47) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK35b33d95;rport (63) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 (91) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=as4c5be4da (53) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (59) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 103 INVITE (16) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Content-Length: 0 (17) [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: (0) [Dec 12 16:37:35] --- (8 headers 0 lines) --- [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:2018 __sip_ack: Acked pending invite 103 [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:2026 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #12 [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235' of Request 103: Match Not Found [Dec 12 16:37:35] SIP Response message for INCOMING dialog INVITE arrived [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:11383 handle_response_invite: SIP response 481 to RE-invite on incoming call 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:35] WARNING[14682]: chan_sip.c:11588 handle_response_invite: Re-invite to non-existing call leg on other UA. SIP dialog '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235'. Giving up. [Dec 12 16:37:35] DEBUG[14682]: chan_sip.c:5474 reqprep: Strict routing enforced for session 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:35] set_destination: Parsing for address/port to send to [Dec 12 16:37:35] set_destination: set destination to 192.168.71.235, port 5060 [Dec 12 16:37:35] Transmitting (no NAT) to 192.168.71.235:5060: ACK sip:9065@192.168.71.235:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK35b33d95;rport From: ;tag=as4c5be4da To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 Contact: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 CSeq: 103 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 12 16:37:36] DEBUG[14683]: channel.c:2680 set_format: Set channel SIP/9065-08201b70 to write format gsm [Dec 12 16:37:36] DEBUG[14683]: res_musiconhold.c:252 ast_moh_files_next: SIP/9065-08201b70 Opened file 6 '/var/lib/asterisk/moh-delavega//track07' [Dec 12 16:37:36] DEBUG[14683]: rtp.c:2425 ast_rtp_raw_write: Difference is 35960, ms is 4515 [Dec 12 16:37:37] <--- SIP read from 192.168.71.141:49166 ---> INVITE sip:9017@192.168.71.2;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK41394a31 From: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb To: Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 Max-Forwards: 70 Date: Tue, 12 Dec 2006 GMT CSeq: 101 INVITE User-Agent: Cisco-CP7911G/8.0 Contact: Expires: 180 Accept: application/sdp Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Supported: replaces,join,norefersub Allow-Events: kpml,dialog Content-Length: 277 Content-Type: application/sdp Content-Disposition: session;handling=optional v=0 o=Cisco-SIPUA 22092 0 IN IP4 192.168.71.141 s=SIP Call t=0 0 m=audio 17884 RTP/AVP 0 8 18 101 c=IN IP4 192.168.71.141 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/0 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: INVITE sip:9017@192.168.71.2;user=phone SIP/2.0 (47) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK41394a31 (59) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb (79) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: (38) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 (59) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Max-Forwards: 70 (16) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: CSeq: 101 INVITE (16) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: User-Agent: Cisco-CP7911G/8.0 (29) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Contact: (53) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Expires: 180 (12) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Accept: application/sdp (23) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 13: Supported: replaces,join,norefersub (35) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 14: Allow-Events: kpml,dialog (25) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 15: Content-Length: 277 (19) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 16: Content-Type: application/sdp (29) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 17: Content-Disposition: session;handling=optional (46) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 18: (0) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: o=Cisco-SIPUA 22092 0 IN IP4 192.168.71.141 (43) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: s=SIP Call (10) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: m=audio 17884 RTP/AVP 0 8 18 101 (32) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.141 (23) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:18 G729/0 (18) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=sendrecv (10) [Dec 12 16:37:37] --- (18 headers 13 lines) --- [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:2523 do_setnat: Setting NAT on RTP to Off [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4203 sip_alloc: Allocating new SIP dialog for 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 - INVITE (With RTP) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:14243 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:1636 parse_sip_options: Begin: parsing SIP "Supported: replaces,join,norefersub" [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:1644 parse_sip_options: Found SIP option: -replaces- [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:1650 parse_sip_options: Matched SIP option: replaces [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:1644 parse_sip_options: Found SIP option: -join- [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:1650 parse_sip_options: Matched SIP option: join [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:1644 parse_sip_options: Found SIP option: -norefersub- [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:1650 parse_sip_options: Matched SIP option: norefersub [Dec 12 16:37:37] Sending to 192.168.71.141 : 5060 (no NAT) [Dec 12 16:37:37] Using INVITE request as basis request - 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:2523 do_setnat: Setting NAT on RTP to Off [Dec 12 16:37:37] Found user '9105' [Dec 12 16:37:37] Found RTP audio format 0 [Dec 12 16:37:37] Found RTP audio format 8 [Dec 12 16:37:37] Found RTP audio format 18 [Dec 12 16:37:37] Found RTP audio format 101 [Dec 12 16:37:37] Peer audio RTP is at port 192.168.71.141:17884 [Dec 12 16:37:37] Found description format PCMU for ID 0 [Dec 12 16:37:37] Found description format PCMA for ID 8 [Dec 12 16:37:37] Found description format G729 for ID 18 [Dec 12 16:37:37] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:37] Found description format telephone-event for ID 101 [Dec 12 16:37:37] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4966 process_sdp: T38 state changed to 0 on channel [Dec 12 16:37:37] Capabilities: us - 0x4 (ulaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 12 16:37:37] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 12 16:37:37] Peer audio RTP is at port 192.168.71.141:17884 [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:5043 process_sdp: We're settling with these formats: 0x4 (ulaw) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:13054 handle_request_invite: Checking SIP call limits for device 9105 [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:2934 update_call_counter: Updating call counter for incoming call [Dec 12 16:37:37] Looking for 9017 in from-sip (domain 192.168.71.2) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:3699 sip_new: *** Our native formats are 0x4 (ulaw) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:3700 sip_new: *** Joint capabilities are 0x4 (ulaw) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:3701 sip_new: *** Our capabilities are 0x4 (ulaw) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:3702 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:3725 sip_new: This channel will not be able to handle video. [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:7784 build_route: build_route: Contact hop: [Dec 12 16:37:37] list_route: hop: [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:13128 handle_request_invite: SIP/9105-08235a60: New call is still down.... Trying... [Dec 12 16:37:37] <--- Transmitting (no NAT) to 192.168.71.141:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK41394a31;received=192.168.71.141 From: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb To: Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 12 16:37:37] DEBUG[14682]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9105-08235a60 [Dec 12 16:37:37] DEBUG[14677]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9105 [Dec 12 16:37:37] DEBUG[14677]: chan_sip.c:14828 sip_devicestate: Checking device state for peer 9105 [Dec 12 16:37:37] DEBUG[14677]: devicestate.c:287 do_state_change: Changing state for SIP/9105 - state 8 (On Hold) [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1767 pbx_extension_helper: Launching 'Answer' [Dec 12 16:37:37] -- Executing [9017@from-sip:1] Answer("SIP/9105-08235a60", "") in new stack [Dec 12 16:37:37] DEBUG[14689]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9105-08235a60 [Dec 12 16:37:37] DEBUG[14677]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9105 [Dec 12 16:37:37] DEBUG[14677]: chan_sip.c:14828 sip_devicestate: Checking device state for peer 9105 [Dec 12 16:37:37] DEBUG[14677]: devicestate.c:287 do_state_change: Changing state for SIP/9105 - state 8 (On Hold) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:3381 sip_answer: SIP answering channel: SIP/9105-08235a60 [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:6255 transmit_response_with_sdp: Setting framing from config on incoming call [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:6003 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:6004 add_sdp: ** Our prefcodec: 0x0 (nothing) [Dec 12 16:37:37] Audio is at 192.168.71.2 port 26268 [Dec 12 16:37:37] Adding codec 0x4 (ulaw) to SDP [Dec 12 16:37:37] Adding non-codec 0x1 (telephone-event) to SDP [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:6155 add_sdp: -- Done with adding codecs to SDP [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:6200 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Dec 12 16:37:37] <--- Reliably Transmitting (no NAT) to 192.168.71.141:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK41394a31;received=192.168.71.141 From: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb To: ;tag=as11f69918 Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 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: 228 v=0 o=root 14689 14689 IN IP4 192.168.71.2 s=session c=IN IP4 192.168.71.2 t=0 0 m=audio 26268 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv <------------> [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #13 [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '9105' [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1767 pbx_extension_helper: Launching 'Set' [Dec 12 16:37:37] -- Executing [9017@from-sip:2] Set("SIP/9105-08235a60", "GROUP(sip-in-use)=9105") in new stack [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1767 pbx_extension_helper: Launching 'Goto' [Dec 12 16:37:37] -- Executing [9017@from-sip:3] Goto("SIP/9105-08235a60", "order-internal|9017|1") in new stack [Dec 12 16:37:37] -- Goto (order-internal,9017,1) [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1767 pbx_extension_helper: Launching 'Macro' [Dec 12 16:37:37] -- Executing [9017@order-internal:1] Macro("SIP/9105-08235a60", "sip-ext-dial|9017") in new stack [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1767 pbx_extension_helper: Launching 'Set' [Dec 12 16:37:37] -- Executing [s@macro-sip-ext-dial:1] Set("SIP/9105-08235a60", "ext=9017") in new stack [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '0' [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1688 pbx_substitute_variables_helper_full: Expression result is '0' [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1767 pbx_extension_helper: Launching 'GotoIf' [Dec 12 16:37:37] -- Executing [s@macro-sip-ext-dial:2] GotoIf("SIP/9105-08235a60", "0?3:6") in new stack [Dec 12 16:37:37] -- Goto (macro-sip-ext-dial,s,6) [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1767 pbx_extension_helper: Launching 'NoOp' [Dec 12 16:37:37] -- Executing [s@macro-sip-ext-dial:6] NoOp("SIP/9105-08235a60", ""Agent not in use"") in new stack [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1767 pbx_extension_helper: Launching 'Set' [Dec 12 16:37:37] -- Executing [s@macro-sip-ext-dial:7] Set("SIP/9105-08235a60", "OUTBOUND_GROUP=9017@sip-in-use") in new stack [Dec 12 16:37:37] DEBUG[14689]: pbx.c:1767 pbx_extension_helper: Launching 'Dial' [Dec 12 16:37:37] -- Executing [s@macro-sip-ext-dial:8] Dial("SIP/9105-08235a60", "SIP/9017|25") in new stack [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:14886 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4203 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Dec 12 16:37:37] DEBUG[14690]: app_queue.c:546 changethread: Device 'SIP/9105' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. [Dec 12 16:37:37] DEBUG[14691]: app_queue.c:546 changethread: Device 'SIP/9105' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. [Dec 12 16:37:37] -- SIP Seeding peer from astdb: '9017' at 9017@192.168.71.183:5060 for 3600 [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:2523 do_setnat: Setting NAT on RTP to Off [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:3699 sip_new: *** Our native formats are 0x4 (ulaw) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:3700 sip_new: *** Joint capabilities are 0x0 (nothing) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:3701 sip_new: *** Our capabilities are 0x4 (ulaw) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:3702 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:3704 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:3725 sip_new: This channel will not be able to handle video. [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:16449 sip_set_rtp_peer: Early remote bridge setting SIP '39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2' - Sending media to 192.168.71.141 [Dec 12 16:37:37] DEBUG[14689]: rtp.c:1518 ast_rtp_make_compatible: Seeded SDP of 'SIP/9017-0823bf50' with that of 'SIP/9105-08235a60' [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-macro-sip-ext-dial-s-8. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable MACRO_DEPTH. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable OUTBOUND_GROUP. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-macro-sip-ext-dial-s-7. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-macro-sip-ext-dial-s-6. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-macro-sip-ext-dial-s-2. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable ext. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-macro-sip-ext-dial-s-1. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable ARG1. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable MACRO_PRIORITY. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable MACRO_CONTEXT. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable MACRO_EXTEN. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-order-internal-9017-1. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-from-sip-9017-3. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable GROUP_sip-in-use. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-from-sip-9017-2. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable STACK-from-sip-9017-1. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Dec 12 16:37:37] DEBUG[14689]: channel.c:3145 ast_channel_inherit_variables: Not copying variable SIPURI. [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:2774 sip_call: Outgoing Call for 9017 [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:2934 update_call_counter: Updating call counter for outgoing call [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:2782 sip_call: Our T38 capability (0), joint T38 capability (0) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:6003 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: False [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:6004 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Dec 12 16:37:37] Audio is at 192.168.71.2 port 16074 [Dec 12 16:37:37] Adding codec 0x4 (ulaw) to SDP [Dec 12 16:37:37] Adding non-codec 0x1 (telephone-event) to SDP [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:6155 add_sdp: -- Done with adding codecs to SDP [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:6200 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 0: INVITE sip:9017@192.168.71.183:5060;transport=udp SIP/2.0 (57) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport (63) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 2: From: "Simon Coy" ;tag=as04808233 (56) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 3: To: (48) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 4: Contact: (32) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 5: Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 (54) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 9: Date: Tue, 12 Dec 2006 15:37:37 GMT (35) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 11: Supported: replaces (19) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 12: Content-Type: application/sdp (29) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 13: Content-Length: 232 (19) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4430 parse_request: Header 14: (0) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4462 parse_request: Line: o=root 14689 14689 IN IP4 192.168.71.141 (40) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4462 parse_request: Line: s=session (9) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.141 (23) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4462 parse_request: Line: m=audio 17884 RTP/AVP 0 101 (27) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4462 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:4462 parse_request: Line: a=sendrecv (10) [Dec 12 16:37:37] Reliably Transmitting (no NAT) to 192.168.71.183:5060: INVITE sip:9017@192.168.71.183:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport From: "Simon Coy" ;tag=as04808233 To: Contact: Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Tue, 12 Dec 2006 15:37:37 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 232 v=0 o=root 14689 14689 IN IP4 192.168.71.141 s=session c=IN IP4 192.168.71.141 t=0 0 m=audio 17884 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- [Dec 12 16:37:37] DEBUG[14689]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #15 [Dec 12 16:37:37] -- Called 9017 [Dec 12 16:37:37] <--- SIP read from 192.168.71.141:49166 ---> ACK sip:9017@192.168.71.2:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK28068266 From: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb To: ;tag=as11f69918 Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 Max-Forwards: 70 Date: Tue, 12 Dec 2006 GMT CSeq: 101 ACK User-Agent: Cisco-CP7911G/8.0 Content-Length: 0 <-------------> [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: ACK sip:9017@192.168.71.2:5060 SIP/2.0 (38) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK28068266 (59) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb (79) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=as11f69918 (53) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 (59) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Max-Forwards: 70 (16) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: CSeq: 101 ACK (13) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: User-Agent: Cisco-CP7911G/8.0 (29) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Content-Length: 0 (17) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: (0) [Dec 12 16:37:37] --- (10 headers 0 lines) --- [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:14243 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:2026 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #13 [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141' of Response 101: Match Not Found [Dec 12 16:37:37] <--- SIP read from 192.168.71.183:49163 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport From: "Simon Coy" ;tag=as04808233 To: Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 Date: Tue, 12 Dec 2006 GMT CSeq: 102 INVITE Server: Cisco-CP7911G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Allow-Events: kpml,dialog Content-Length: 0 <-------------> [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 100 Trying (18) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport (63) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Simon Coy" ;tag=as04808233 (56) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: (48) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 (54) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Contact: (53) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Allow-Events: kpml,dialog (25) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Content-Length: 0 (17) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: (0) [Dec 12 16:37:37] --- (12 headers 0 lines) --- [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:2069 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #15 - INVITE (got response) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:2078 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2' Request 102: Found [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:11385 handle_response_invite: SIP response 100 to standard invite [Dec 12 16:37:37] <--- SIP read from 192.168.71.183:49163 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport From: "Simon Coy" ;tag=as04808233 To: ;tag=000ab8b5bccf0007f225391b-ceac5cd8 Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 Date: Tue, 12 Dec 2006 GMT CSeq: 102 INVITE Server: Cisco-CP7911G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Allow-Events: kpml,dialog Content-Length: 0 <-------------> [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport (63) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Simon Coy" ;tag=as04808233 (56) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=000ab8b5bccf0007f225391b-ceac5cd8 (86) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 (54) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Contact: (53) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Allow-Events: kpml,dialog (25) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Content-Length: 0 (17) [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: (0) [Dec 12 16:37:37] --- (12 headers 0 lines) --- [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:2078 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2' Request 102: Found [Dec 12 16:37:37] DEBUG[14682]: chan_sip.c:11385 handle_response_invite: SIP response 180 to standard invite [Dec 12 16:37:37] DEBUG[14682]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9017-0823bf50 [Dec 12 16:37:37] -- SIP/9017-0823bf50 is ringing [Dec 12 16:37:37] DEBUG[14689]: rtp.c:1453 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/9105-08235a60' with that of 'SIP/9017-0823bf50' [Dec 12 16:37:37] DEBUG[14689]: channel.c:2279 ast_indicate_data: Driver for channel 'SIP/9105-08235a60' does not support indication 3, emulating it [Dec 12 16:37:37] DEBUG[14689]: channel.c:2680 set_format: Set channel SIP/9105-08235a60 to write format slin [Dec 12 16:37:37] DEBUG[14689]: channel.c:1860 ast_settimeout: Scheduling timer at 160 sample intervals [Dec 12 16:37:37] DEBUG[14677]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9017 [Dec 12 16:37:37] DEBUG[14677]: chan_sip.c:14828 sip_devicestate: Checking device state for peer 9017 [Dec 12 16:37:37] DEBUG[14677]: devicestate.c:287 do_state_change: Changing state for SIP/9017 - state 1 (Not in use) [Dec 12 16:37:37] DEBUG[14692]: app_queue.c:546 changethread: Device 'SIP/9017' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 12 16:37:37] DEBUG[14689]: channel.c:2177 __ast_read: Generator got voice, switching to phase locked mode [Dec 12 16:37:37] DEBUG[14689]: channel.c:1860 ast_settimeout: Scheduling timer at 0 sample intervals [Dec 12 16:37:37] DEBUG[14689]: rtp.c:2555 ast_rtp_write: Ooh, format changed from unknown to ulaw [Dec 12 16:37:37] DEBUG[14689]: rtp.c:2572 ast_rtp_write: Created smoother: format: 4 ms: 20 len: 160 [Dec 12 16:37:39] <--- SIP read from 192.168.71.235:49176 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK34975cb8;rport From: ;tag=as4c5be4da To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 Date: Tue, 12 Dec 2006 GMT CSeq: 102 INVITE Server: Cisco-CP7911G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Supported: replaces,join,norefersub Allow-Events: kpml,dialog Content-Length: 207 Content-Type: application/sdp Content-Disposition: session;handling=optional v=0 o=Cisco-SIPUA 941 1 IN IP4 192.168.71.235 s=SIP Call t=0 0 m=audio 21750 RTP/AVP 0 101 c=IN IP4 192.168.71.235 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK34975cb8;rport (63) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: ;tag=as4c5be4da (55) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 (89) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (59) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Contact: (53) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Supported: replaces,join,norefersub (35) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Allow-Events: kpml,dialog (25) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: Content-Length: 207 (19) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 13: Content-Type: application/sdp (29) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 14: Content-Disposition: session;handling=optional (46) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 15: (0) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: o=Cisco-SIPUA 941 1 IN IP4 192.168.71.235 (41) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: s=SIP Call (10) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: m=audio 21750 RTP/AVP 0 101 (27) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.235 (23) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=sendrecv (10) [Dec 12 16:37:39] --- (15 headers 10 lines) --- [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235' of Request 102: Match Found [Dec 12 16:37:39] SIP Response message for INCOMING dialog INVITE arrived [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:11383 handle_response_invite: SIP response 200 to RE-invite on incoming call 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:39] Found RTP audio format 0 [Dec 12 16:37:39] Found RTP audio format 101 [Dec 12 16:37:39] Peer audio RTP is at port 192.168.71.235:21750 [Dec 12 16:37:39] Found description format PCMU for ID 0 [Dec 12 16:37:39] Found description format telephone-event for ID 101 [Dec 12 16:37:39] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4966 process_sdp: T38 state changed to 0 on channel SIP/9065-08201b70 [Dec 12 16:37:39] Capabilities: us - 0x4 (ulaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 12 16:37:39] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 12 16:37:39] Peer audio RTP is at port 192.168.71.235:21750 [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:5043 process_sdp: We're settling with these formats: 0x4 (ulaw) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:5050 process_sdp: We have an owner, now see if we need to change this call [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:11503 handle_response_invite: Strange... The other side of the bridge does not have a udptl struct [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:11508 handle_response_invite: T38 state changed to 0 on channel SIP [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:11511 handle_response_invite: T38 state changed to 0 on channel SIP/9065-08201b70 [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:5474 reqprep: Strict routing enforced for session 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:39] set_destination: Parsing for address/port to send to [Dec 12 16:37:39] set_destination: set destination to 192.168.71.235, port 5060 [Dec 12 16:37:39] Transmitting (no NAT) to 192.168.71.235:5060: ACK sip:9065@192.168.71.235:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK5135a0f7;rport From: ;tag=as4c5be4da To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 Contact: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 12 16:37:39] <--- SIP read from 192.168.71.141:49166 ---> INVITE sip:9017@192.168.71.2:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK232bea17 From: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb To: ;tag=as11f69918 Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 Max-Forwards: 70 Date: Tue, 12 Dec 2006 GMT CSeq: 102 INVITE User-Agent: Cisco-CP7911G/8.0 Contact: Accept: application/sdp Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Supported: replaces,join,norefersub Allow-Events: kpml,dialog Content-Length: 277 Content-Type: application/sdp Content-Disposition: session;handling=optional v=0 o=Cisco-SIPUA 22092 1 IN IP4 192.168.71.141 s=SIP Call t=0 0 m=audio 17884 RTP/AVP 0 8 18 101 c=IN IP4 192.168.71.141 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/0 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendonly <-------------> [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: INVITE sip:9017@192.168.71.2:5060 SIP/2.0 (41) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK232bea17 (59) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb (79) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=as11f69918 (53) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 (59) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Max-Forwards: 70 (16) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: CSeq: 102 INVITE (16) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: User-Agent: Cisco-CP7911G/8.0 (29) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Contact: (53) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Accept: application/sdp (23) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: Supported: replaces,join,norefersub (35) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 13: Allow-Events: kpml,dialog (25) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 14: Content-Length: 277 (19) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 15: Content-Type: application/sdp (29) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 16: Content-Disposition: session;handling=optional (46) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 17: (0) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: o=Cisco-SIPUA 22092 1 IN IP4 192.168.71.141 (43) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: s=SIP Call (10) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: m=audio 17884 RTP/AVP 0 8 18 101 (32) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.141 (23) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:18 G729/0 (18) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:18 annexb=no (19) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-15 (15) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4462 parse_request: Line: a=sendonly (10) [Dec 12 16:37:39] --- (17 headers 13 lines) --- [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:14243 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 12 16:37:39] Sending to 192.168.71.141 : 5060 (no NAT) [Dec 12 16:37:39] Found RTP audio format 0 [Dec 12 16:37:39] Found RTP audio format 8 [Dec 12 16:37:39] Found RTP audio format 18 [Dec 12 16:37:39] Found RTP audio format 101 [Dec 12 16:37:39] Peer audio RTP is at port 192.168.71.141:17884 [Dec 12 16:37:39] Found description format PCMU for ID 0 [Dec 12 16:37:39] Found description format PCMA for ID 8 [Dec 12 16:37:39] Found description format G729 for ID 18 [Dec 12 16:37:39] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:39] Found description format telephone-event for ID 101 [Dec 12 16:37:39] Got unsupported a:fmtp in SDP offer [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4966 process_sdp: T38 state changed to 0 on channel SIP/9105-08235a60 [Dec 12 16:37:39] Capabilities: us - 0x4 (ulaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 12 16:37:39] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 12 16:37:39] Peer audio RTP is at port 192.168.71.141:17884 [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:5043 process_sdp: We're settling with these formats: 0x4 (ulaw) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:5050 process_sdp: We have an owner, now see if we need to change this call [Dec 12 16:37:39] DEBUG[14682]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9105 [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:13106 handle_request_invite: Got a SIP re-invite for call 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:13195 handle_request_invite: SIP/9105-08235a60: This call is UP.... [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:6255 transmit_response_with_sdp: Setting framing from config on incoming call [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:6003 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:6004 add_sdp: ** Our prefcodec: 0x0 (nothing) [Dec 12 16:37:39] Audio is at 192.168.71.2 port 26268 [Dec 12 16:37:39] Adding codec 0x4 (ulaw) to SDP [Dec 12 16:37:39] Adding non-codec 0x1 (telephone-event) to SDP [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:6155 add_sdp: -- Done with adding codecs to SDP [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:6200 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Dec 12 16:37:39] DEBUG[14677]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9105 [Dec 12 16:37:39] DEBUG[14677]: chan_sip.c:14828 sip_devicestate: Checking device state for peer 9105 [Dec 12 16:37:39] DEBUG[14677]: devicestate.c:287 do_state_change: Changing state for SIP/9105 - state 8 (On Hold) [Dec 12 16:37:39] <--- Reliably Transmitting (no NAT) to 192.168.71.141:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK232bea17;received=192.168.71.141 From: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb To: ;tag=as11f69918 Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 228 v=0 o=root 14689 14690 IN IP4 192.168.71.2 s=session c=IN IP4 192.168.71.2 t=0 0 m=audio 26268 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly <------------> [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #18 [Dec 12 16:37:39] DEBUG[14693]: app_queue.c:546 changethread: Device 'SIP/9105' changed to state '8' (On Hold) but we don't care because they're not a member of any queue. [Dec 12 16:37:39] <--- SIP read from 192.168.71.141:49166 ---> ACK sip:9017@192.168.71.2:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bKf4f73294 From: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb To: ;tag=as11f69918 Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 Max-Forwards: 70 Date: Tue, 12 Dec 2006 GMT CSeq: 102 ACK User-Agent: Cisco-CP7911G/8.0 Content-Length: 0 <-------------> [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: ACK sip:9017@192.168.71.2:5060 SIP/2.0 (38) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bKf4f73294 (59) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb (79) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=as11f69918 (53) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 (59) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Max-Forwards: 70 (16) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: CSeq: 102 ACK (13) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: User-Agent: Cisco-CP7911G/8.0 (29) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Content-Length: 0 (17) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: (0) [Dec 12 16:37:39] --- (10 headers 0 lines) --- [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:14243 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:2026 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18 [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141' of Response 102: Match Not Found [Dec 12 16:37:39] <--- SIP read from 192.168.71.141:49166 ---> REFER sip:9065@192.168.71.2:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK13d0e8cd From: ;tag=0019068bf14b000de0707056-fa25b367 To: "Jean-Francois Stenuit" ;tag=as6f57693e Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 Max-Forwards: 70 Date: Tue, 12 Dec 2006 GMT CSeq: 102 REFER User-Agent: Cisco-CP7911G/8.0 Contact: Refer-To: Referred-By: Content-Length: 0 <-------------> [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: REFER sip:9065@192.168.71.2:5060 SIP/2.0 (40) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK13d0e8cd (59) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: ;tag=0019068bf14b000de0707056-fa25b367 (88) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: "Jean-Francois Stenuit" ;tag=as6f57693e (66) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 (54) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Max-Forwards: 70 (16) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: CSeq: 102 REFER (15) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: User-Agent: Cisco-CP7911G/8.0 (29) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Contact: (53) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Refer-To: (175) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Referred-By: (57) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: Content-Length: 0 (17) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 13: (0) [Dec 12 16:37:39] --- (13 headers 0 lines) --- [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:14243 handle_request: **** Received REFER (9) - Command in SIP REFER [Dec 12 16:37:39] Call 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 got a SIP call transfer from callee: (REFER)! [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:8509 get_refer_info: Attended transfer: Will use Replace-Call-ID : 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 (No check of from/to tags) [Dec 12 16:37:39] SIP transfer to extension 9017@from-sip by 9105@192.168.71.141:5060 [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:13604 handle_request_refer: SIP attended transfer: Transferer channel SIP/9105-0821e1d0, transferee channel SIP/9065-08201b70 [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:13620 handle_request_refer: Got SIP transfer, applying to bridged peer 'SIP/9065-08201b70' [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:8365 get_sip_pvt_byid_locked: Looking for callid 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 (fromtag 0019068bf14b000eebde1628-8d1eecbb totag as11f69918) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:8389 get_sip_pvt_byid_locked: Matched INCOMING call - their tag is 0019068bf14b000eebde1628-8d1eecbb Our tag is as11f69918 [Dec 12 16:37:39] <--- Transmitting (no NAT) to 192.168.71.141:5060 ---> SIP/2.0 202 Accepted Via: SIP/2.0/UDP 192.168.71.141:5060;branch=z9hG4bK13d0e8cd;received=192.168.71.141 From: ;tag=0019068bf14b000de0707056-fa25b367 To: "Jean-Francois Stenuit" ;tag=as6f57693e Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 CSeq: 102 REFER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:13352 local_attended_transfer: SIP attended transfer: Error: No target channel [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:5474 reqprep: Strict routing enforced for session 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 [Dec 12 16:37:39] set_destination: Parsing for address/port to send to [Dec 12 16:37:39] set_destination: set destination to 192.168.71.141, port 5060 [Dec 12 16:37:39] Reliably Transmitting (no NAT) to 192.168.71.141:5060: NOTIFY sip:9105@192.168.71.141:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK6e6a115b;rport From: "Jean-Francois Stenuit" ;tag=as6f57693e To: ;tag=0019068bf14b000de0707056-fa25b367 Contact: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 CSeq: 103 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=102 Subscription-state: terminated;reason=noresource Content-Type: message/sipfrag;version=2.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 33 SIP/2.0 503 Service Unavailable --- [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #19 [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:14452 sipsock_read: SIP message could not be handled, bad request: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 [Dec 12 16:37:39] -- Stopped music on hold on SIP/9065-08201b70 [Dec 12 16:37:39] DEBUG[14683]: channel.c:2680 set_format: Set channel SIP/9065-08201b70 to write format ulaw [Dec 12 16:37:39] DEBUG[14683]: channel.c:1860 ast_settimeout: Scheduling timer at 0 sample intervals [Dec 12 16:37:39] <--- SIP read from 192.168.71.141:49175 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK6e6a115b;rport From: "Jean-Francois Stenuit" ;tag=as6f57693e To: ;tag=0019068bf14b000de0707056-fa25b367 Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 Date: Tue, 12 Dec 2006 GMT CSeq: 103 NOTIFY Content-Length: 0 <-------------> [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK6e6a115b;rport (63) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Jean-Francois Stenuit" ;tag=as6f57693e (68) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=0019068bf14b000de0707056-fa25b367 (86) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 (54) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 103 NOTIFY (16) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Content-Length: 0 (17) [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: (0) [Dec 12 16:37:39] --- (8 headers 0 lines) --- [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:2026 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #19 [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2' of Request 103: Match Not Found [Dec 12 16:37:39] DEBUG[14682]: chan_sip.c:11908 handle_response: Got OK on REFER Notify message *CLI> *CLI> *CLI> *CLI> *CLI> *CLI> *CLI> *CLI> stop now [Dec 12 16:37:50] DEBUG[14671]: channel.c:1346 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/9017-0823bf50' [Dec 12 16:37:50] DEBUG[14671]: channel.c:1346 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/9105-08235a60' [Dec 12 16:37:50] DEBUG[14671]: channel.c:1346 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/9105-0821e1d0' [Dec 12 16:37:50] DEBUG[14671]: channel.c:1346 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/9065-08201b70' [Dec 12 16:37:50] Beginning asterisk shutdown.... [Dec 12 16:37:50] DEBUG[14689]: channel.c:1558 ast_hangup: Hanging up channel 'SIP/9017-0823bf50' [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:3233 sip_hangup: Hangup call SIP/9017-0823bf50, SIP callid 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2) [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:3241 sip_hangup: update_call_counter(9017) - decrement call limit counter on hangup [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:2934 update_call_counter: Updating call counter for outgoing call [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:3254 sip_hangup: Hanging up channel in state Ringing (not UP) [Dec 12 16:37:50] Scheduling destruction of SIP dialog '39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2' in 32000 ms (Method: INVITE) [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:2018 __sip_ack: Acked pending invite 102 [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2' of Request 102: Match Not Found [Dec 12 16:37:50] Reliably Transmitting (no NAT) to 192.168.71.183:5060: CANCEL sip:9017@192.168.71.183:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport From: "Simon Coy" ;tag=as04808233 To: Contact: Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 CSeq: 102 CANCEL User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #21 [Dec 12 16:37:50] Scheduling destruction of SIP dialog '39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2' in 32000 ms (Method: INVITE) [Dec 12 16:37:50] DEBUG[14689]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9017-0823bf50 [Dec 12 16:37:50] -- No one is available to answer at this time (1:0/0/0) [Dec 12 16:37:50] DEBUG[14689]: rtp.c:1416 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Dec 12 16:37:50] DEBUG[14689]: app_dial.c:1639 dial_exec_full: Exiting with DIALSTATUS=NOANSWER. [Dec 12 16:37:50] DEBUG[14689]: app_macro.c:267 _macro_exec: Extension s, macroexten 9017, priority 8 returned normally even though call was hung up [Dec 12 16:37:50] DEBUG[14689]: pbx.c:2383 __ast_pbx_run: Extension 9017, priority 1 returned normally even though call was hung up [Dec 12 16:37:50] DEBUG[14689]: channel.c:2680 set_format: Set channel SIP/9105-08235a60 to write format ulaw [Dec 12 16:37:50] DEBUG[14689]: cdr.c:896 ast_cdr_detach: Dropping CDR ! [Dec 12 16:37:50] DEBUG[14689]: channel.c:1558 ast_hangup: Hanging up channel 'SIP/9105-08235a60' [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:3233 sip_hangup: Hangup call SIP/9105-08235a60, SIP callid 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141) [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:3241 sip_hangup: update_call_counter(9105) - decrement call limit counter on hangup [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:2934 update_call_counter: Updating call counter for incoming call [Dec 12 16:37:50] Scheduling destruction of SIP dialog '0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141' in 32000 ms (Method: ACK) [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:5474 reqprep: Strict routing enforced for session 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 [Dec 12 16:37:50] set_destination: Parsing for address/port to send to [Dec 12 16:37:50] set_destination: set destination to 192.168.71.141, port 5060 [Dec 12 16:37:50] Reliably Transmitting (no NAT) to 192.168.71.141:5060: BYE sip:9105@192.168.71.141:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK51c44489;rport From: ;tag=as11f69918 To: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb Contact: Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 CSeq: 102 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 12 16:37:50] DEBUG[14689]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #24 [Dec 12 16:37:50] DEBUG[14689]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9105-08235a60 [Dec 12 16:37:50] DEBUG[14683]: rtp.c:2738 bridge_native_loop: Oooh, got a hangup [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:16452 sip_set_rtp_peer: Sending reinvite on SIP '4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2' - It's audio soon redirected to IP 192.168.71.2 [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:5474 reqprep: Strict routing enforced for session 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 [Dec 12 16:37:50] set_destination: Parsing for address/port to send to [Dec 12 16:37:50] set_destination: set destination to 192.168.71.141, port 5060 [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:6003 add_sdp: ** Our capability: 0x4 (ulaw) Video flag: True [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:6004 add_sdp: ** Our prefcodec: 0x4 (ulaw) [Dec 12 16:37:50] Audio is at 192.168.71.2 port 13730 [Dec 12 16:37:50] Adding codec 0x4 (ulaw) to SDP [Dec 12 16:37:50] Adding non-codec 0x1 (telephone-event) to SDP [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:6155 add_sdp: -- Done with adding codecs to SDP [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:6200 add_sdp: Done building SDP. Settling with this capability: 0x4 (ulaw) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:1585 initialize_initreq: Initializing already initialized SIP dialog 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 (presumably reinvite) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 0: INVITE sip:9105@192.168.71.141:5060;transport=udp SIP/2.0 (57) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK1cadd1e5;rport (63) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 2: From: "Jean-Francois Stenuit" ;tag=as6f57693e (68) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=0019068bf14b000de0707056-fa25b367 (86) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 4: Contact: (32) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 5: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 (54) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 6: CSeq: 104 INVITE (16) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 10: Supported: replaces (19) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 12: Content-Type: application/sdp (29) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 13: Content-Length: 228 (19) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4430 parse_request: Header 14: (0) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: v=0 (3) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: o=root 14683 14685 IN IP4 192.168.71.2 (38) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: s=session (9) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: c=IN IP4 192.168.71.2 (21) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: t=0 0 (5) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: m=audio 13730 RTP/AVP 0 101 (27) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:4462 parse_request: Line: a=recvonly (10) [Dec 12 16:37:50] Reliably Transmitting (no NAT) to 192.168.71.141:5060: INVITE sip:9105@192.168.71.141:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK1cadd1e5;rport From: "Jean-Francois Stenuit" ;tag=as6f57693e To: ;tag=0019068bf14b000de0707056-fa25b367 Contact: Call-ID: 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2 CSeq: 104 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: 228 v=0 o=root 14683 14685 IN IP4 192.168.71.2 s=session c=IN IP4 192.168.71.2 t=0 0 m=audio 13730 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly --- [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #25 [Dec 12 16:37:50] DEBUG[14683]: channel.c:3873 ast_channel_bridge: Returning from native bridge, channels: SIP/9065-08201b70, SIP/9105-0821e1d0 [Dec 12 16:37:50] DEBUG[14683]: channel.c:1558 ast_hangup: Hanging up channel 'SIP/9105-0821e1d0' [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:3233 sip_hangup: Hangup call SIP/9105-0821e1d0, SIP callid 4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:3241 sip_hangup: update_call_counter(9105) - decrement call limit counter on hangup [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:2934 update_call_counter: Updating call counter for outgoing call [Dec 12 16:37:50] Scheduling destruction of SIP dialog '4eb6de8b2d896be0067d5d1e6037bb51@192.168.71.2' in 32000 ms (Method: REFER) [Dec 12 16:37:50] DEBUG[14683]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9105-0821e1d0 [Dec 12 16:37:50] DEBUG[14683]: rtp.c:1416 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Dec 12 16:37:50] DEBUG[14683]: app_dial.c:1639 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Dec 12 16:37:50] DEBUG[14683]: app_macro.c:253 _macro_exec: Spawn extension (macro-sip-ext-dial,s,8) exited non-zero on 'SIP/9065-08201b70' in macro 'sip-ext-dial' [Dec 12 16:37:50] DEBUG[14683]: pbx.c:2363 __ast_pbx_run: Spawn extension (macro-sip-ext-dial,s,8) exited non-zero on 'SIP/9065-08201b70' [Dec 12 16:37:50] == Spawn extension (macro-sip-ext-dial, s, 8) exited non-zero on 'SIP/9065-08201b70' [Dec 12 16:37:50] DEBUG[14683]: cdr.c:896 ast_cdr_detach: Dropping CDR ! [Dec 12 16:37:50] DEBUG[14683]: channel.c:1558 ast_hangup: Hanging up channel 'SIP/9065-08201b70' [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:3233 sip_hangup: Hangup call SIP/9065-08201b70, SIP callid 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:3241 sip_hangup: update_call_counter(9065) - decrement call limit counter on hangup [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:2934 update_call_counter: Updating call counter for incoming call [Dec 12 16:37:50] Scheduling destruction of SIP dialog '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235' in 32000 ms (Method: ACK) [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:5474 reqprep: Strict routing enforced for session 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 [Dec 12 16:37:50] set_destination: Parsing for address/port to send to [Dec 12 16:37:50] set_destination: set destination to 192.168.71.235, port 5060 [Dec 12 16:37:50] Reliably Transmitting (no NAT) to 192.168.71.235:5060: BYE sip:9065@192.168.71.235:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK0094c63c;rport From: ;tag=as4c5be4da To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 Contact: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 CSeq: 104 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 12 16:37:50] DEBUG[14683]: chan_sip.c:1927 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #28 [Dec 12 16:37:50] DEBUG[14683]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/9065-08201b70 [Dec 12 16:37:50] Executing last minute cleanups [Dec 12 16:37:50] == Destroying musiconhold processes [Dec 12 16:37:50] Asterisk cleanly ending (0). [Dec 12 16:37:50] DEBUG[14671]: asterisk.c:1189 quit_handler: Asterisk ending (0). [Dec 12 16:37:50] <--- SIP read from 192.168.71.183:49163 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport From: "Simon Coy" ;tag=as04808233 To: ;tag=000ab8b5bccf0007f225391b-ceac5cd8 Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 Date: Tue, 12 Dec 2006 GMT CSeq: 102 CANCEL Server: Cisco-CP7911G/8.0 Content-Length: 0 <-------------> [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport (63) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Simon Coy" ;tag=as04808233 (56) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=000ab8b5bccf0007f225391b-ceac5cd8 (86) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 (54) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 CANCEL (16) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Content-Length: 0 (17) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: (0) [Dec 12 16:37:50] --- (9 headers 0 lines) --- [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:2026 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #21 [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2' of Request 102: Match Not Found [Dec 12 16:37:50] <--- SIP read from 192.168.71.141:49166 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK51c44489;rport From: ;tag=as11f69918 To: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 Date: Tue, 12 Dec 2006 GMT CSeq: 102 BYE Server: Cisco-CP7911G/8.0 Content-Length: 0 <-------------> [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK51c44489;rport (63) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: ;tag=as11f69918 (55) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: "Simon Coy" ;tag=0019068bf14b000eebde1628-8d1eecbb (77) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141 (59) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 BYE (13) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Content-Length: 0 (17) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: (0) [Dec 12 16:37:50] --- (9 headers 0 lines) --- [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:2026 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #24 [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141' of Request 102: Match Not Found [Dec 12 16:37:50] SIP Response message for INCOMING dialog BYE arrived [Dec 12 16:37:50] Really destroying SIP dialog '0019068b-f14b0007-6b5645ba-47a71615@192.168.71.141' Method: ACK [Dec 12 16:37:50] DEBUG[14677]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9017 [Dec 12 16:37:50] DEBUG[14677]: chan_sip.c:14828 sip_devicestate: Checking device state for peer 9017 [Dec 12 16:37:50] DEBUG[14677]: devicestate.c:287 do_state_change: Changing state for SIP/9017 - state 1 (Not in use) [Dec 12 16:37:50] <--- SIP read from 192.168.71.183:49163 ---> SIP/2.0 487 Request Cancelled Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport From: "Simon Coy" ;tag=as04808233 To: ;tag=000ab8b5bccf0007f225391b-ceac5cd8 Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 Date: Tue, 12 Dec 2006 GMT CSeq: 102 INVITE Server: Cisco-CP7911G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE Allow-Events: kpml,dialog Content-Length: 0 <-------------> [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 487 Request Cancelled (29) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport (63) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: "Simon Coy" ;tag=as04808233 (56) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: ;tag=000ab8b5bccf0007f225391b-ceac5cd8 (86) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 (54) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Contact: (53) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE (75) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 10: Allow-Events: kpml,dialog (25) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 11: Content-Length: 0 (17) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 12: (0) [Dec 12 16:37:50] --- (12 headers 0 lines) --- [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2' of Request 102: Match Found [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:2934 update_call_counter: Updating call counter for outgoing call [Dec 12 16:37:50] Transmitting (no NAT) to 192.168.71.183:5060: ACK sip:9017@192.168.71.183:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK04abe839;rport From: "Simon Coy" ;tag=as04808233 To: ;tag=000ab8b5bccf0007f225391b-ceac5cd8 Contact: Call-ID: 39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 12 16:37:50] Really destroying SIP dialog '39dd95623dd10ca96cd4bc786e8b5193@192.168.71.2' Method: INVITE [Dec 12 16:37:50] <--- SIP read from 192.168.71.235:49176 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK0094c63c;rport From: ;tag=as4c5be4da To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 Date: Tue, 12 Dec 2006 GMT CSeq: 104 BYE Server: Cisco-CP7911G/8.0 Content-Length: 0 <-------------> [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 0: SIP/2.0 200 OK (14) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.71.2:5060;branch=z9hG4bK0094c63c;rport (63) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 2: From: ;tag=as4c5be4da (55) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 3: To: "Jean-Francois Stenuit" ;tag=001906964b5700066e13d759-e6cb5f88 (89) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 4: Call-ID: 00190696-4b570006-2c2e3f03-2939539a@192.168.71.235 (59) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 5: Date: Tue, 12 Dec 2006 GMT (27) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 6: CSeq: 104 BYE (13) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 7: Server: Cisco-CP7911G/8.0 (25) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 8: Content-Length: 0 (17) [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:4430 parse_request: Header 9: (0) [Dec 12 16:37:50] --- (9 headers 0 lines) --- [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:2026 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #28 [Dec 12 16:37:50] DEBUG[14682]: chan_sip.c:2036 __sip_ack: Stopping retransmission on '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235' of Request 104: Match Not Found [Dec 12 16:37:50] SIP Response message for INCOMING dialog BYE arrived [Dec 12 16:37:50] Really destroying SIP dialog '00190696-4b570006-2c2e3f03-2939539a@192.168.71.235' Method: ACK [Dec 12 16:37:50] DEBUG[14677]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 9105 [Dec 12 16:37:50] DEBUG[14677]: chan_sip.c:14828 sip_devicestate: Checking device state for peer 9105 [Dec 12 16:37:50] DEBUG[14677]: devicestate.c:287 do_state_change: Changing state for SIP/9105 - state 8 (On Hold)