[Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: INVITE sip:0215890000@10.105.177.21 SIP/2.0 (43) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.36.2.1:5060;branch=z9hG4bK309d6a37;rport (60) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: From: "0315400414" ;tag=as63be1f58 (60) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: To: (34) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: Contact: (35) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: Call-ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 (51) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: CSeq: 102 INVITE (16) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: Date: Fri, 17 Aug 2007 15:23:13 GMT (35) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 11: Supported: replaces (19) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 12: Content-Type: application/sdp (29) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 13: Content-Length: 367 (19) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 14: (0) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: v=0 (3) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: o=root 6268 6268 IN IP4 10.36.2.1 (33) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: s=session (9) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: c=IN IP4 10.36.2.1 (18) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: t=0 0 (5) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: m=audio 18874 RTP/AVP 4 18 3 8 0 97 (35) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=fmtp:4 annexa=no (18) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=fmtp:18 annexb=no (19) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:97 telephone-event/8000 (32) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=fmtp:97 0-16 (14) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=silenceSupp:off - - - - (25) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=ptime:20 (10) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=sendrecv (10) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:2624 do_setnat: Setting NAT on RTP to Off [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:2629 do_setnat: Setting NAT on VRTP to Off [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:2634 do_setnat: Setting NAT on UDPTL to Off [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4374 sip_alloc: Allocating new SIP dialog for 49e42c29470e377f05b117122165e17d@10.36.2.1 - INVITE (With RTP) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:14857 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:1688 parse_sip_options: Begin: parsing SIP "Supported: replaces" [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:1696 parse_sip_options: Found SIP option: -replaces- [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:1702 parse_sip_options: Matched SIP option: replaces [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:2624 do_setnat: Setting NAT on RTP to Off [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:2629 do_setnat: Setting NAT on VRTP to Off [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:2634 do_setnat: Setting NAT on UDPTL to Off [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:5225 process_sdp: T38 state changed to 0 on channel [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:5305 process_sdp: We're settling with these formats: 0x10f (g723|gsm|ulaw|alaw|g729) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:13539 handle_request_invite: Checking SIP call limits for device [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:3058 update_call_counter: Updating call counter for incoming call [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:3866 sip_new: *** Our native formats are 0x100 (g729) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:3867 sip_new: *** Joint capabilities are 0x10f (g723|gsm|ulaw|alaw|g729) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:3868 sip_new: *** Our capabilities are 0x10f (g723|gsm|ulaw|alaw|g729) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:3869 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:3892 sip_new: This channel will not be able to handle video. [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:8064 build_route: build_route: Contact hop: [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:13614 handle_request_invite: SIP/10.36.2.1-009531d0: New call is still down.... Trying... [Aug 17 18:23:13] DEBUG[5330]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/10.36.2.1-009531d0 [Aug 17 18:23:13] DEBUG[5308]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 10.36.2.1 [Aug 17 18:23:13] DEBUG[5308]: chan_sip.c:15482 sip_devicestate: Checking device state for peer 10.36.2.1 [Aug 17 18:23:13] DEBUG[5308]: devicestate.c:287 do_state_change: Changing state for SIP/10.36.2.1 - state 2 (In use) [Aug 17 18:23:13] DEBUG[9980]: pbx.c:1811 pbx_extension_helper: Launching 'Dial' -- Executing [0215890000@world:1] Dial("SIP/10.36.2.1-009531d0", "SIP/patton/0215890000") in new stack [Aug 17 18:23:13] ERROR[9980]: pbx.c:521 pbx_exec: Write 0 as hangupcause for channel SIP/10.36.2.1-009531d0 [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:15548 sip_request_call: Asked to create a SIP channel with formats: 0x100 (g729) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4374 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:2670 create_addr_from_peer: Our T38 capability (3856) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:2624 do_setnat: Setting NAT on RTP to Off [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:2634 do_setnat: Setting NAT on UDPTL to Off [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:3866 sip_new: *** Our native formats are 0x100 (g729) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:3867 sip_new: *** Joint capabilities are 0x0 (nothing) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:3868 sip_new: *** Our capabilities are 0x109 (g723|alaw|g729) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:3869 sip_new: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:3871 sip_new: *** Our preferred formats from the incoming channel are 0x100 (g729) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:3892 sip_new: This channel will not be able to handle video. [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:17136 sip_set_rtp_peer: Early remote bridge setting SIP '2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21' - Sending media to 10.36.2.1 [Aug 17 18:23:13] DEBUG[9980]: rtp.c:1621 ast_rtp_make_compatible: Seeded SDP of 'SIP/patton-007fdfe0' with that of 'SIP/10.36.2.1-009531d0' [Aug 17 18:23:13] DEBUG[9980]: channel.c:3473 ast_channel_inherit_variables: Not copying variable STACK-world-0215890000-1. [Aug 17 18:23:13] DEBUG[9980]: channel.c:3473 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Aug 17 18:23:13] DEBUG[9980]: channel.c:3473 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Aug 17 18:23:13] DEBUG[9980]: channel.c:3473 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Aug 17 18:23:13] DEBUG[9980]: channel.c:3473 ast_channel_inherit_variables: Not copying variable SIPURI. [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:2882 sip_call: Outgoing Call for 0215890000 [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:3058 update_call_counter: Updating call counter for outgoing call [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:2897 sip_call: Our T38 capability (3856), joint T38 capability (3856) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:6262 add_sdp: ** Our capability: 0x109 (g723|alaw|g729) Video flag: False [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:6263 add_sdp: ** Our prefcodec: 0x100 (g729) Audio is at 10.105.177.21 port 19516 Adding codec 0x100 (g729) to SDP Adding codec 0x1 (g723) to SDP Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:6394 add_sdp: -- Done with adding codecs to SDP [Aug 17 18:23:13] DEBUG[9980]: channel.c:2525 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:6439 add_sdp: Done building SDP. Settling with this capability: 0x109 (g723|alaw|g729) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 0: INVITE sip:0215890000@10.105.177.14 SIP/2.0 (43) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK1f7692fd (58) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 2: From: "0315400414" ;tag=as5edcbb80 (64) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 3: To: (34) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 4: Contact: (39) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 5: Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 (55) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 6: CSeq: 102 INVITE (16) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 9: Date: Fri, 17 Aug 2007 15:23:13 GMT (35) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 11: Supported: replaces (19) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 12: Content-Type: application/sdp (29) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 13: Content-Length: 320 (19) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 14: (0) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: v=0 (3) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: o=root 5302 5302 IN IP4 10.36.2.1 (33) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: s=session (9) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: c=IN IP4 10.36.2.1 (18) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: t=0 0 (5) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: m=audio 18874 RTP/AVP 18 4 8 97 (31) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=fmtp:18 annexb=no (19) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=rtpmap:4 G723/8000 (20) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=fmtp:4 annexa=no (18) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=rtpmap:97 telephone-event/8000 (32) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=fmtp:97 0-16 (14) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=silenceSupp:off - - - - (25) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=ptime:20 (10) [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 10.105.177.14:5060: INVITE sip:0215890000@10.105.177.14 SIP/2.0 Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK1f7692fd From: "0315400414" ;tag=as5edcbb80 To: Contact: Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Fri, 17 Aug 2007 15:23:13 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 320 v=0 o=root 5302 5302 IN IP4 10.36.2.1 s=session c=IN IP4 10.36.2.1 t=0 0 m=audio 18874 RTP/AVP 18 4 8 97 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:4 G723/8000 a=fmtp:4 annexa=no a=rtpmap:8 PCMA/8000 a=rtpmap:97 telephone-event/8000 a=fmtp:97 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:2017 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #277292 -- Called patton/0215890000 [Aug 17 18:23:13] DEBUG[9981]: app_queue.c:546 changethread: Device 'SIP/10.36.2.1' changed to state '2' (In use) but we don't care because they're not a member of any queue. <--- SIP read from 10.105.177.14:5060 ---> SIP/2.0 100 Trying Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 CSeq: 102 INVITE From: "0315400414" ;tag=as5edcbb80 To: ;tag=995d84911a7d552 Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK1f7692fd Content-Length: 0 User-Agent: Patton SN2400 MxSF v3.2.8.45 00A0BA01D704 R3.21 2007-07-13 H323 SIP <-------------> [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: SIP/2.0 100 Trying (18) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 (55) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: CSeq: 102 INVITE (16) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: From: "0315400414" ;tag=as5edcbb80 (64) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: To: ;tag=995d84911a7d552 (54) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK1f7692fd (58) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: Content-Length: 0 (17) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: User-Agent: Patton SN2400 MxSF v3.2.8.45 00A0BA01D704 R3.21 2007-07-13 H323 SIP (79) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: (0) --- (8 headers 0 lines) --- [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4427 find_call: = Found Their Call ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 Their Tag Our tag: as5edcbb80 [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:2171 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #277292 - INVITE (got response) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:2180 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21' Request 102: Found [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:11729 handle_response_invite: SIP response 100 to standard invite sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> <--- SIP read from 10.105.177.14:5060 ---> SIP/2.0 180 Ringing Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 CSeq: 102 INVITE From: "0315400414" ;tag=as5edcbb80 To: ;tag=995d84911a7d552 Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK1f7692fd Content-Length: 0 Contact: sip:0215890000@10.105.177.14:5060 User-Agent: Patton SN2400 MxSF v3.2.8.45 00A0BA01D704 R3.21 2007-07-13 H323 SIP <-------------> [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 (55) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: CSeq: 102 INVITE (16) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: From: "0315400414" ;tag=as5edcbb80 (64) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: To: ;tag=995d84911a7d552 (54) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK1f7692fd (58) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: Content-Length: 0 (17) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: Contact: sip:0215890000@10.105.177.14:5060 (42) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: User-Agent: Patton SN2400 MxSF v3.2.8.45 00A0BA01D704 R3.21 2007-07-13 H323 SIP (79) [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: (0) --- (9 headers 0 lines) --- [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:4427 find_call: = Found Their Call ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 Their Tag 995d84911a7d552 Our tag: as5edcbb80 [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:2180 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21' Request 102: Found [Aug 17 18:23:13] DEBUG[5330]: chan_sip.c:11729 handle_response_invite: SIP response 180 to standard invite [Aug 17 18:23:13] DEBUG[5330]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/patton-007fdfe0 [Aug 17 18:23:13] DEBUG[5308]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - patton [Aug 17 18:23:13] DEBUG[5308]: chan_sip.c:15482 sip_devicestate: Checking device state for peer patton [Aug 17 18:23:13] DEBUG[5308]: devicestate.c:287 do_state_change: Changing state for SIP/patton - state 1 (Not in use) -- SIP/patton-007fdfe0 is ringing [Aug 17 18:23:13] DEBUG[9980]: chan_sip.c:17136 sip_set_rtp_peer: Early remote bridge setting SIP '49e42c29470e377f05b117122165e17d@10.36.2.1' - Sending media to 10.105.177.21 [Aug 17 18:23:13] DEBUG[9980]: rtp.c:1550 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/10.36.2.1-009531d0' with that of 'SIP/patton-007fdfe0' [Aug 17 18:23:13] DEBUG[9982]: app_queue.c:546 changethread: Device 'SIP/patton' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> <--- SIP read from 10.105.177.14:5060 ---> SIP/2.0 200 OK Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 CSeq: 102 INVITE From: "0315400414" ;tag=as5edcbb80 To: ;tag=995d84911a7d552 Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK1f7692fd Content-Length: 225 Content-Type: application/sdp Supported: replaces Contact: sip:0215890000@10.105.177.14:5060 User-Agent: Patton SN2400 MxSF v3.2.8.45 00A0BA01D704 R3.21 2007-07-13 H323 SIP v=0 o=MxSIP 0 41 IN IP4 10.105.177.14 s=SIP Call c=IN IP4 10.105.177.14 t=0 0 m=audio 4956 RTP/AVP 18 8 97 a=rtpmap:18 G729/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:97 telephone-event/8000 a=fmtp:18 annexb=no a=sendrecv <-------------> [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: SIP/2.0 200 OK (14) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 (55) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: CSeq: 102 INVITE (16) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: From: "0315400414" ;tag=as5edcbb80 (64) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: To: ;tag=995d84911a7d552 (54) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK1f7692fd (58) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: Content-Length: 225 (19) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: Content-Type: application/sdp (29) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Supported: replaces (19) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: Contact: sip:0215890000@10.105.177.14:5060 (42) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 10: User-Agent: Patton SN2400 MxSF v3.2.8.45 00A0BA01D704 R3.21 2007-07-13 H323 SIP (79) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 11: (0) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: v=0 (3) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: o=MxSIP 0 41 IN IP4 10.105.177.14 (33) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: s=SIP Call (10) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: c=IN IP4 10.105.177.14 (22) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: t=0 0 (5) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: m=audio 4956 RTP/AVP 18 8 97 (28) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:18 G729/8000 (21) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:97 telephone-event/8000 (32) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=fmtp:18 annexb=no (19) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=sendrecv (10) --- (11 headers 11 lines) --- [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 088451d3614185f047d82e13626e8b3a@89.36.1.1 Their Tag as3929ff56 Our tag: as29d38c97 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 078850c94c65bf5551f0f3a975e47f55@10.105.177.12 Their Tag as7ba33119 Our tag: as2a0131e3 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 24e247a22c8f98f262730ee0773e047d@89.36.3.1 Their Tag as1f465ff0 Our tag: as2fc697ce [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = Found Their Call ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 Their Tag 995d84911a7d552 Our tag: as5edcbb80 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:2120 __sip_ack: Acked pending invite 102 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:2138 __sip_ack: Stopping retransmission on '2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21' of Request 102: Match Not Found [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:11729 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 18 Found RTP audio format 8 Found RTP audio format 97 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4992 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.105.177.14:4956 Found description format G729 for ID 18 Found description format PCMA for ID 8 Found description format telephone-event for ID 97 Got unsupported a:fmtp in SDP offer [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:5225 process_sdp: T38 state changed to 0 on channel SIP/patton-007fdfe0 Capabilities: us - 0x109 (g723|alaw|g729), peer - audio=0x108 (alaw|g729)/video=0x0 (nothing), combined - 0x108 (alaw|g729) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 10.105.177.14:4956 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:5305 process_sdp: We're settling with these formats: 0x108 (alaw|g729) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:5312 process_sdp: We have an owner, now see if we need to change this call [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:3058 update_call_counter: Updating call counter for outgoing call [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:8064 build_route: build_route: Contact hop: sip:0215890000@10.105.177.14:5060 list_route: hop: [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:5712 reqprep: Strict routing enforced for session 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 set_destination: Parsing for address/port to send to set_destination: set destination to 10.105.177.14, port 5060 Transmitting (no NAT) to 10.105.177.14:5060: ACK sip:0215890000@10.105.177.14:5060 SIP/2.0 Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK45c8856c From: "0315400414" ;tag=as5edcbb80 To: ;tag=995d84911a7d552 Contact: Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Aug 17 18:23:19] DEBUG[9980]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/patton-007fdfe0 -- SIP/patton-007fdfe0 answered SIP/10.36.2.1-009531d0 [Aug 17 18:23:19] DEBUG[9980]: chan_sip.c:17136 sip_set_rtp_peer: Early remote bridge setting SIP '49e42c29470e377f05b117122165e17d@10.36.2.1' - Sending media to 10.105.177.14 [Aug 17 18:23:19] DEBUG[9980]: rtp.c:1550 ast_rtp_early_bridge: Setting early bridge SDP of 'SIP/10.36.2.1-009531d0' with that of 'SIP/patton-007fdfe0' [Aug 17 18:23:19] DEBUG[9980]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/10.36.2.1-009531d0 [Aug 17 18:23:19] DEBUG[9980]: chan_sip.c:3524 sip_answer: SIP answering channel: SIP/10.36.2.1-009531d0 [Aug 17 18:23:19] DEBUG[9980]: chan_sip.c:6498 transmit_response_with_sdp: Setting framing from config on incoming call [Aug 17 18:23:19] DEBUG[9980]: chan_sip.c:6262 add_sdp: ** Our capability: 0x108 (alaw|g729) Video flag: True [Aug 17 18:23:19] DEBUG[9980]: chan_sip.c:6263 add_sdp: ** Our prefcodec: 0x0 (nothing) [Aug 17 18:23:19] DEBUG[9980]: chan_sip.c:6394 add_sdp: -- Done with adding codecs to SDP [Aug 17 18:23:19] DEBUG[9980]: channel.c:2525 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 17 18:23:19] DEBUG[9980]: chan_sip.c:6439 add_sdp: Done building SDP. Settling with this capability: 0x108 (alaw|g729) [Aug 17 18:23:19] DEBUG[9980]: chan_sip.c:2017 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #277297 -- Native bridging SIP/10.36.2.1-009531d0 and SIP/patton-007fdfe0 [Aug 17 18:23:19] DEBUG[5308]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - patton [Aug 17 18:23:19] DEBUG[5308]: chan_sip.c:15482 sip_devicestate: Checking device state for peer patton [Aug 17 18:23:19] DEBUG[5308]: devicestate.c:287 do_state_change: Changing state for SIP/patton - state 1 (Not in use) [Aug 17 18:23:19] DEBUG[5308]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 10.36.2.1 [Aug 17 18:23:19] DEBUG[5308]: chan_sip.c:15482 sip_devicestate: Checking device state for peer 10.36.2.1 [Aug 17 18:23:19] DEBUG[5308]: devicestate.c:287 do_state_change: Changing state for SIP/10.36.2.1 - state 2 (In use) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: ACK sip:0215890000@10.105.177.21 SIP/2.0 (40) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.36.2.1:5060;branch=z9hG4bK5bd7611d;rport (60) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: From: "0315400414" ;tag=as63be1f58 (60) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: To: ;tag=as54e0d989 (49) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: Contact: (35) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: Call-ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 (51) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: CSeq: 102 ACK (13) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: Content-Length: 0 (17) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 10: (0) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 088451d3614185f047d82e13626e8b3a@89.36.1.1 Their Tag as3929ff56 Our tag: as29d38c97 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 078850c94c65bf5551f0f3a975e47f55@10.105.177.12 Their Tag as7ba33119 Our tag: as2a0131e3 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 24e247a22c8f98f262730ee0773e047d@89.36.3.1 Their Tag as1f465ff0 Our tag: as2fc697ce [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 Their Tag 995d84911a7d552 Our tag: as5edcbb80 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = Found Their Call ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 Their Tag as63be1f58 Our tag: as54e0d989 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:14857 handle_request: **** Received ACK (6) - Command in SIP ACK [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:2128 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #277297 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:2138 __sip_ack: Stopping retransmission on '49e42c29470e377f05b117122165e17d@10.36.2.1' of Response 102: Match Not Found [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: INVITE sip:0215890000@10.105.177.21 SIP/2.0 (43) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.36.2.1:5060;branch=z9hG4bK4f0b5e92;rport (60) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: From: "0315400414" ;tag=as63be1f58 (60) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: To: ;tag=as54e0d989 (49) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: Contact: (35) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: Call-ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 (51) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: CSeq: 103 INVITE (16) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 10: Supported: replaces (19) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 12: Content-Type: application/sdp (29) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 13: Content-Length: 230 (19) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 14: (0) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: v=0 (3) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: o=root 6268 6269 IN IP4 10.36.2.85 (34) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: s=session (9) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: c=IN IP4 10.36.2.85 (19) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: t=0 0 (5) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: m=audio 3334 RTP/AVP 8 97 (25) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:97 telephone-event/8000 (32) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=fmtp:97 0-16 (14) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=silenceSupp:off - - - - (25) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=ptime:20 (10) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=sendrecv (10) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 088451d3614185f047d82e13626e8b3a@89.36.1.1 Their Tag as3929ff56 Our tag: as29d38c97 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 078850c94c65bf5551f0f3a975e47f55@10.105.177.12 Their Tag as7ba33119 Our tag: as2a0131e3 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 24e247a22c8f98f262730ee0773e047d@89.36.3.1 Their Tag as1f465ff0 Our tag: as2fc697ce [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 Their Tag 995d84911a7d552 Our tag: as5edcbb80 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = Found Their Call ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 Their Tag as63be1f58 Our tag: as54e0d989 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:14857 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:5225 process_sdp: T38 state changed to 0 on channel SIP/10.36.2.1-009531d0 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:5305 process_sdp: We're settling with these formats: 0x8 (alaw) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:5312 process_sdp: We have an owner, now see if we need to change this call [Aug 17 18:23:19] DEBUG[5330]: channel.c:3002 set_format: Set channel SIP/10.36.2.1-009531d0 to read format g729 [Aug 17 18:23:19] DEBUG[5330]: channel.c:3002 set_format: Set channel SIP/10.36.2.1-009531d0 to write format g729 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:13591 handle_request_invite: Got a SIP re-invite for call 49e42c29470e377f05b117122165e17d@10.36.2.1 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:13688 handle_request_invite: SIP/10.36.2.1-009531d0: This call is UP.... [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:6498 transmit_response_with_sdp: Setting framing from config on incoming call [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:6262 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:6263 add_sdp: ** Our prefcodec: 0x0 (nothing) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:6394 add_sdp: -- Done with adding codecs to SDP [Aug 17 18:23:19] DEBUG[5330]: channel.c:2525 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:6439 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Aug 17 18:23:19] DEBUG[9983]: app_queue.c:546 changethread: Device 'SIP/patton' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 17 18:23:19] DEBUG[9984]: app_queue.c:546 changethread: Device 'SIP/10.36.2.1' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: ACK sip:0215890000@10.105.177.21 SIP/2.0 (40) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.36.2.1:5060;branch=z9hG4bK01e5033f;rport (60) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: From: "0315400414" ;tag=as63be1f58 (60) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: To: ;tag=as54e0d989 (49) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: Contact: (35) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: Call-ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 (51) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: CSeq: 103 ACK (13) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: Content-Length: 0 (17) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 10: (0) [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 088451d3614185f047d82e13626e8b3a@89.36.1.1 Their Tag as3929ff56 Our tag: as29d38c97 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 078850c94c65bf5551f0f3a975e47f55@10.105.177.12 Their Tag as7ba33119 Our tag: as2a0131e3 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 24e247a22c8f98f262730ee0773e047d@89.36.3.1 Their Tag as1f465ff0 Our tag: as2fc697ce [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 Their Tag 995d84911a7d552 Our tag: as5edcbb80 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:4427 find_call: = Found Their Call ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 Their Tag as63be1f58 Our tag: as54e0d989 [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:14857 handle_request: **** Received ACK (6) - Command in SIP ACK [Aug 17 18:23:19] DEBUG[5330]: chan_sip.c:2138 __sip_ack: Stopping retransmission on '49e42c29470e377f05b117122165e17d@10.36.2.1' of Response 103: Match Found sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> sun-fire-x2100*CLI> <--- SIP read from 10.105.177.14:5060 ---> INVITE sip:0315400414@10.105.177.21 SIP/2.0 Via: SIP/2.0/UDP 10.105.177.14:5060;branch=z9hG4bKa37bfe597 Max-Forwards: 70 Content-Length: 141 To: "0315400414" ;tag=as5edcbb80 From: ;tag=995d84911a7d552 Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 CSeq: 1634273991 INVITE Supported: timer Content-Type: application/sdp Contact: sip:0215890000@10.105.177.14:5060 Supported: replaces User-Agent: Patton SN2400 MxSF v3.2.8.45 00A0BA01D704 R3.21 2007-07-13 H323 SIP v=0 o=MxSIP 0 43 IN IP4 10.105.177.14 s=SIP Call c=IN IP4 10.105.177.14 t=0 0 m=audio 4956 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=sendrecv <-------------> [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: INVITE sip:0315400414@10.105.177.21 SIP/2.0 (43) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.105.177.14:5060;branch=z9hG4bKa37bfe597 (59) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: Max-Forwards: 70 (16) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: Content-Length: 141 (19) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: To: "0315400414" ;tag=as5edcbb80 (62) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: From: ;tag=995d84911a7d552 (56) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 (55) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: CSeq: 1634273991 INVITE (23) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Supported: timer (16) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: Content-Type: application/sdp (29) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 10: Contact: sip:0215890000@10.105.177.14:5060 (42) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 11: Supported: replaces (19) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 12: User-Agent: Patton SN2400 MxSF v3.2.8.45 00A0BA01D704 R3.21 2007-07-13 H323 SIP (79) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 13: (0) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: v=0 (3) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: o=MxSIP 0 43 IN IP4 10.105.177.14 (33) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: s=SIP Call (10) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: c=IN IP4 10.105.177.14 (22) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: t=0 0 (5) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: m=audio 4956 RTP/AVP 8 (22) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=sendrecv (10) --- (13 headers 8 lines) --- [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 088451d3614185f047d82e13626e8b3a@89.36.1.1 Their Tag as3929ff56 Our tag: as29d38c97 [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 078850c94c65bf5551f0f3a975e47f55@10.105.177.12 Their Tag as7ba33119 Our tag: as2a0131e3 [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 24e247a22c8f98f262730ee0773e047d@89.36.3.1 Their Tag as1f465ff0 Our tag: as2fc697ce [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4427 find_call: = Found Their Call ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 Their Tag 995d84911a7d552 Our tag: as5edcbb80 [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:14857 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:1688 parse_sip_options: Begin: parsing SIP "Supported: timer" [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:1696 parse_sip_options: Found SIP option: -timer- [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:1702 parse_sip_options: Matched SIP option: timer Sending to 10.105.177.14 : 5060 (no NAT) Found RTP audio format 8 [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4992 process_sdp: Peer doesn't provide T.38 UDPTL Peer audio RTP is at port 10.105.177.14:4956 Found description format PCMA for ID 8 [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:5225 process_sdp: T38 state changed to 0 on channel SIP/patton-007fdfe0 Capabilities: us - 0x109 (g723|alaw|g729), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing) Peer audio RTP is at port 10.105.177.14:4956 [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:5305 process_sdp: We're settling with these formats: 0x8 (alaw) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:5312 process_sdp: We have an owner, now see if we need to change this call [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:5317 process_sdp: Oooh, we need to change our audio formats since our peer supports only 0x8 (alaw) and not 0x100 (g729) [Aug 17 18:23:20] DEBUG[5330]: channel.c:3002 set_format: Set channel SIP/patton-007fdfe0 to read format g729 [Aug 17 18:23:20] DEBUG[5330]: channel.c:3002 set_format: Set channel SIP/patton-007fdfe0 to write format g729 [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:13591 handle_request_invite: Got a SIP re-invite for call 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:13688 handle_request_invite: SIP/patton-007fdfe0: This call is UP.... <--- Transmitting (no NAT) to 10.105.177.14:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.105.177.14:5060;branch=z9hG4bKa37bfe597;received=10.105.177.14 From: ;tag=995d84911a7d552 To: "0315400414" ;tag=as5edcbb80 Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 CSeq: 1634273991 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:6498 transmit_response_with_sdp: Setting framing from config on incoming call [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:6262 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:6263 add_sdp: ** Our prefcodec: 0x100 (g729) Audio is at 10.105.177.21 port 19516 Adding codec 0x8 (alaw) to SDP [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:6394 add_sdp: -- Done with adding codecs to SDP [Aug 17 18:23:20] DEBUG[5330]: channel.c:2525 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:6439 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) <--- Transmitting (no NAT) to 10.105.177.14:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.105.177.14:5060;branch=z9hG4bKa37bfe597;received=10.105.177.14 From: ;tag=995d84911a7d552 To: "0315400414" ;tag=as5edcbb80 Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 CSeq: 1634273991 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 176 v=0 o=root 5302 5303 IN IP4 10.36.2.1 s=session c=IN IP4 10.36.2.1 t=0 0 m=audio 18874 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> sun-fire-x2100*CLI> <--- SIP read from 10.105.177.14:5060 ---> ACK sip:0315400414@10.105.177.21 SIP/2.0 Via: SIP/2.0/UDP 10.105.177.14:5060;branch=z9hG4bK25861e766 Max-Forwards: 70 Content-Length: 0 To: "0315400414" ;tag=as5edcbb80 From: ;tag=995d84911a7d552 Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 CSeq: 1634273991 ACK Contact: sip:0215890000@10.105.177.14:5060 User-Agent: Patton SN2400 MxSF v3.2.8.45 00A0BA01D704 R3.21 2007-07-13 H323 SIP sun-fire-x2100*CLI> <-------------> [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: ACK sip:0315400414@10.105.177.21 SIP/2.0 (40) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.105.177.14:5060;branch=z9hG4bK25861e766 (59) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: Max-Forwards: 70 (16) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: Content-Length: 0 (17) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: To: "0315400414" ;tag=as5edcbb80 (62) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: From: ;tag=995d84911a7d552 (56) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 (55) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: CSeq: 1634273991 ACK (20) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Contact: sip:0215890000@10.105.177.14:5060 (42) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: User-Agent: Patton SN2400 MxSF v3.2.8.45 00A0BA01D704 R3.21 2007-07-13 H323 SIP (79) [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 10: (0) --- (10 headers 0 lines) --- [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 088451d3614185f047d82e13626e8b3a@89.36.1.1 Their Tag as3929ff56 Our tag: as29d38c97 [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 078850c94c65bf5551f0f3a975e47f55@10.105.177.12 Their Tag as7ba33119 Our tag: as2a0131e3 [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 24e247a22c8f98f262730ee0773e047d@89.36.3.1 Their Tag as1f465ff0 Our tag: as2fc697ce [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:4427 find_call: = Found Their Call ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 Their Tag 995d84911a7d552 Our tag: as5edcbb80 [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:14857 handle_request: **** Received ACK (6) - Command in SIP ACK [Aug 17 18:23:20] DEBUG[5330]: chan_sip.c:2138 __sip_ack: Stopping retransmission on '2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21' of Response 1634273991: Match Found [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4374 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: OPTIONS sip:0315400228@86.35.132.52:56330;user=phone SIP/2.0 (60) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK0e09bb47;rport (64) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: From: "asterisk" ;tag=as06cd7245 (60) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: To: (50) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: Contact: (37) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: Call-ID: 238771647240858823d1caa805714d45@10.105.177.21 (55) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: CSeq: 102 OPTIONS (17) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: Date: Fri, 17 Aug 2007 15:23:21 GMT (35) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 11: Supported: replaces (19) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 12: Content-Length: 0 (17) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:2017 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #277298 [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4374 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: OPTIONS sip:0315400226@86.35.151.20:5060;user=phone SIP/2.0 (59) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK486d3d1f (58) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: From: "asterisk" ;tag=as7418d10e (60) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: To: (49) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: Contact: (37) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: Call-ID: 0a563518244cff251b4e76032c68b29e@10.105.177.21 (55) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: CSeq: 102 OPTIONS (17) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: Date: Fri, 17 Aug 2007 15:23:21 GMT (35) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 11: Supported: replaces (19) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 12: Content-Length: 0 (17) [Aug 17 18:23:21] DEBUG[5330]: chan_sip.c:2017 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #277300 [Aug 17 18:23:22] DEBUG[5330]: chan_sip.c:1879 retrans_pkt: SIP TIMER: Not rescheduling id #277298:OPTIONS (Method 3) (No timer T1) [Aug 17 18:23:22] DEBUG[5330]: chan_sip.c:1879 retrans_pkt: SIP TIMER: Not rescheduling id #277300:OPTIONS (Method 3) (No timer T1) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:1879 retrans_pkt: SIP TIMER: Not rescheduling id #277298:OPTIONS (Method 3) (No timer T1) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:1879 retrans_pkt: SIP TIMER: Not rescheduling id #277300:OPTIONS (Method 3) (No timer T1) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: OPTIONS sip:10.105.177.21 SIP/2.0 (33) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.36.2.1:5060;branch=z9hG4bK25d5273e;rport (60) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: From: "asterisk" ;tag=as55b7334b (56) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: To: (23) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: Contact: (33) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: Call-ID: 76f657036c6403e749d3804065e89b68@10.36.2.1 (51) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: CSeq: 102 OPTIONS (17) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: Date: Fri, 17 Aug 2007 15:23:23 GMT (35) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 11: Supported: replaces (19) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 12: Content-Length: 0 (17) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 13: (0) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 0a563518244cff251b4e76032c68b29e@10.105.177.21 Their Tag Our tag: as7418d10e [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 238771647240858823d1caa805714d45@10.105.177.21 Their Tag Our tag: as06cd7245 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 088451d3614185f047d82e13626e8b3a@89.36.1.1 Their Tag as3929ff56 Our tag: as29d38c97 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 078850c94c65bf5551f0f3a975e47f55@10.105.177.12 Their Tag as7ba33119 Our tag: as2a0131e3 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 24e247a22c8f98f262730ee0773e047d@89.36.3.1 Their Tag as1f465ff0 Our tag: as2fc697ce [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 Their Tag 995d84911a7d552 Our tag: as5edcbb80 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 Their Tag as63be1f58 Our tag: as54e0d989 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 4592c838018864535dd35e2503c45727@10.105.177.21 Their Tag A5FC96C-4F0 Our tag: as0ae196ce [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 399366671231200095110@10.105.177.78 Their Tag 1c399367066 Our tag: as19e16ff6 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 10484813182012000142358@10.105.177.227 Their Tag 1c1752108385 Our tag: as3d0e18ea [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 1290954126201200035541@10.105.177.78 Their Tag 1c355853549 Our tag: as6ee27270 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 258028bd18c3e24b12c8a81a523037f4@10.105.177.21 Their Tag 4f28c5b80bd8db8 Our tag: as5e67f232 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 2e8eddc65ec718ae323c9d067387e851@10.36.2.1 Their Tag as13101be6 Our tag: as44effbb5 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 3977a6bf27d7c2906d3a4a5e129d908e@10.105.177.21 Their Tag 3e3de76d5c05c49 Our tag: as4c59c763 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 40db31ca59191d9a291253367ab81c32@10.36.2.1 Their Tag as550abcba Our tag: as68d5feb7 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 653016bc51fd6e0302ceb7213766722d@10.105.177.21 Their Tag f6f9443e542952e Our tag: as2a03624f [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 52d44f5966ca0b624158bba9119d5fab@10.36.2.1 Their Tag as161eae47 Our tag: as466515bd [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 68bf892928d6c8623eb8a82e6ad20450@10.105.177.21 Their Tag 8b4523921221384 Our tag: as0e03c2d3 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 6e3225461bca98b90bda744b55d2e9af@10.36.2.1 Their Tag as20500b9f Our tag: as4b84a6e7 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 111b3d3143798d592d378f115a8b7b61@10.105.177.21 Their Tag 39c2d22409d4a50 Our tag: as474ef5eb [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 76eb56b52d987373700fdb9249f87564@10.36.2.1 Their Tag as7ce31eac Our tag: as5ca6d1e5 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 6de455d27b119a0e68be9c5955c1d189@10.105.177.21 Their Tag 11767c6b809cfa2 Our tag: as7627da31 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 7cfc3ac83223f9381c07d3a82c372c6f@10.36.2.1 Their Tag as5554b324 Our tag: as50ffb90a [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 62dcafc845ee17fd76ad0e6b4ec578e4@10.105.177.21 Their Tag 7e9f47124974d5f Our tag: as336f672f [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 0b6fb94a2298f977204972e879b7bea8@10.36.2.1 Their Tag as4362880d Our tag: as0af1ffa4 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 25315fa51d06b1d34cf789492a65b1af@10.105.177.21 Their Tag a0fc7f0ac65bef8 Our tag: as206cc241 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 1cdcbf4072cbd1ae7bfc18f0700aafcd@10.36.2.1 Their Tag as6f0292fc Our tag: as329e2dc3 [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 55fc252864400c9d4affe9bd5223dd65@10.105.177.21 Their Tag e0c922b75a0e392 Our tag: as795d0a0c [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 6e53aa7c2e1070952c1278d01ac2c799@10.36.2.1 Their Tag as37a82481 Our tag: as2a9f6b0e [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 4cebc3dd6925a3763c9c770e2519f9e8@10.105.177.21 Their Tag 1a01b5bf8dab07e Our tag: as4dd9144d [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 75ea5e936d129b734d9deb382e79130e@10.36.2.1 Their Tag as571155ba Our tag: as4d1476ef [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:4374 sip_alloc: Allocating new SIP dialog for 76f657036c6403e749d3804065e89b68@10.36.2.1 - OPTIONS (No RTP) [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:14857 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Aug 17 18:23:23] DEBUG[5330]: chan_sip.c:15075 sipsock_read: SIP message could not be handled, bad request: 76f657036c6403e749d3804065e89b68@10.36.2.1 [Aug 17 18:23:24] DEBUG[5330]: chan_sip.c:1879 retrans_pkt: SIP TIMER: Not rescheduling id #277298:OPTIONS (Method 3) (No timer T1) [Aug 17 18:23:24] DEBUG[5330]: chan_sip.c:2059 __sip_autodestruct: Auto destroying SIP dialog '1290954126201200035541@10.105.177.78' [Aug 17 18:23:24] DEBUG[5330]: chan_sip.c:3164 sip_destroy: Destroying SIP dialog 1290954126201200035541@10.105.177.78 Really destroying SIP dialog '1290954126201200035541@10.105.177.78' Method: REGISTER [Aug 17 18:23:24] DEBUG[5330]: chan_sip.c:1879 retrans_pkt: SIP TIMER: Not rescheduling id #277300:OPTIONS (Method 3) (No timer T1) [Aug 17 18:23:25] DEBUG[5330]: chan_sip.c:1879 retrans_pkt: SIP TIMER: Not rescheduling id #277298:OPTIONS (Method 3) (No timer T1) [Aug 17 18:23:25] DEBUG[5330]: chan_sip.c:3164 sip_destroy: Destroying SIP dialog 238771647240858823d1caa805714d45@10.105.177.21 Really destroying SIP dialog '238771647240858823d1caa805714d45@10.105.177.21' Method: OPTIONS [Aug 17 18:23:25] DEBUG[5330]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/0315400228 [Aug 17 18:23:25] DEBUG[5308]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 0315400228 [Aug 17 18:23:25] DEBUG[5308]: chan_sip.c:15482 sip_devicestate: Checking device state for peer 0315400228 [Aug 17 18:23:25] DEBUG[5308]: devicestate.c:287 do_state_change: Changing state for SIP/0315400228 - state 1 (Not in use) [Aug 17 18:23:25] DEBUG[9986]: app_queue.c:546 changethread: Device 'SIP/0315400228' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 17 18:23:25] DEBUG[5330]: chan_sip.c:1879 retrans_pkt: SIP TIMER: Not rescheduling id #277300:OPTIONS (Method 3) (No timer T1) [Aug 17 18:23:25] DEBUG[5330]: chan_sip.c:3164 sip_destroy: Destroying SIP dialog 0a563518244cff251b4e76032c68b29e@10.105.177.21 Really destroying SIP dialog '0a563518244cff251b4e76032c68b29e@10.105.177.21' Method: OPTIONS [Aug 17 18:23:25] DEBUG[5330]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/0315400226 [Aug 17 18:23:25] DEBUG[5308]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 0315400226 [Aug 17 18:23:25] DEBUG[5308]: chan_sip.c:15482 sip_devicestate: Checking device state for peer 0315400226 [Aug 17 18:23:25] DEBUG[5308]: devicestate.c:287 do_state_change: Changing state for SIP/0315400226 - state 1 (Not in use) [Aug 17 18:23:25] DEBUG[9987]: app_queue.c:546 changethread: Device 'SIP/0315400226' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: INVITE sip:0215890000@10.105.177.21 SIP/2.0 (43) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.36.2.1:5060;branch=z9hG4bK269fb2ef;rport (60) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: From: "0315400414" ;tag=as63be1f58 (60) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: To: ;tag=as54e0d989 (49) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: Contact: (35) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: Call-ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 (51) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: CSeq: 104 INVITE (16) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 10: Supported: replaces (19) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 12: Content-Type: application/sdp (29) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 13: Content-Length: 229 (19) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 14: (0) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: v=0 (3) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: o=root 6268 6270 IN IP4 10.36.2.1 (33) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: s=session (9) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: c=IN IP4 10.36.2.1 (18) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: t=0 0 (5) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: m=audio 18874 RTP/AVP 8 97 (26) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=rtpmap:97 telephone-event/8000 (32) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=fmtp:97 0-16 (14) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=silenceSupp:off - - - - (25) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=ptime:20 (10) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4671 parse_request: Line: a=sendrecv (10) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 76f657036c6403e749d3804065e89b68@10.36.2.1 Their Tag as55b7334b Our tag: as4622b305 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 088451d3614185f047d82e13626e8b3a@89.36.1.1 Their Tag as3929ff56 Our tag: as29d38c97 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 078850c94c65bf5551f0f3a975e47f55@10.105.177.12 Their Tag as7ba33119 Our tag: as2a0131e3 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 24e247a22c8f98f262730ee0773e047d@89.36.3.1 Their Tag as1f465ff0 Our tag: as2fc697ce [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 Their Tag 995d84911a7d552 Our tag: as5edcbb80 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = Found Their Call ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 Their Tag as63be1f58 Our tag: as54e0d989 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:14857 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:5225 process_sdp: T38 state changed to 0 on channel SIP/10.36.2.1-009531d0 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:5305 process_sdp: We're settling with these formats: 0x8 (alaw) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:5312 process_sdp: We have an owner, now see if we need to change this call [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:13591 handle_request_invite: Got a SIP re-invite for call 49e42c29470e377f05b117122165e17d@10.36.2.1 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:13688 handle_request_invite: SIP/10.36.2.1-009531d0: This call is UP.... [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:6498 transmit_response_with_sdp: Setting framing from config on incoming call [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:6262 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:6263 add_sdp: ** Our prefcodec: 0x0 (nothing) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:6394 add_sdp: -- Done with adding codecs to SDP [Aug 17 18:23:26] DEBUG[5330]: channel.c:2525 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:6439 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 0: BYE sip:0215890000@10.105.177.21 SIP/2.0 (40) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.36.2.1:5060;branch=z9hG4bK25c2a671;rport (60) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 2: From: "0315400414" ;tag=as63be1f58 (60) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 3: To: ;tag=as54e0d989 (49) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 4: Call-ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 (51) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 5: CSeq: 105 BYE (13) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 6: User-Agent: Asterisk PBX (24) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 7: Max-Forwards: 70 (16) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 8: Content-Length: 0 (17) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4639 parse_request: Header 9: (0) [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 76f657036c6403e749d3804065e89b68@10.36.2.1 Their Tag as55b7334b Our tag: as4622b305 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 088451d3614185f047d82e13626e8b3a@89.36.1.1 Their Tag as3929ff56 Our tag: as29d38c97 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 078850c94c65bf5551f0f3a975e47f55@10.105.177.12 Their Tag as7ba33119 Our tag: as2a0131e3 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 24e247a22c8f98f262730ee0773e047d@89.36.3.1 Their Tag as1f465ff0 Our tag: as2fc697ce [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = No match Their Call ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 Their Tag 995d84911a7d552 Our tag: as5edcbb80 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:4427 find_call: = Found Their Call ID: 49e42c29470e377f05b117122165e17d@10.36.2.1 Their Tag as63be1f58 Our tag: as54e0d989 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:14857 handle_request: **** Received BYE (8) - Command in SIP BYE [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:1641 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 49e42c29470e377f05b117122165e17d@10.36.2.1 [Aug 17 18:23:26] DEBUG[5330]: chan_sip.c:14399 handle_request_bye: Received bye, issuing owner hangup [Aug 17 18:23:26] DEBUG[9980]: rtp.c:2918 bridge_native_loop: Oooh, got a hangup [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:17139 sip_set_rtp_peer: Sending reinvite on SIP '2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21' - It's audio soon redirected to IP 10.105.177.21 [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:5712 reqprep: Strict routing enforced for session 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 set_destination: Parsing for address/port to send to set_destination: set destination to 10.105.177.14, port 5060 [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:6262 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:6263 add_sdp: ** Our prefcodec: 0x100 (g729) Audio is at 10.105.177.21 port 19516 Adding codec 0x8 (alaw) to SDP [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:6394 add_sdp: -- Done with adding codecs to SDP [Aug 17 18:23:26] DEBUG[9980]: channel.c:2525 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:6439 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:1629 initialize_initreq: Initializing already initialized SIP dialog 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 (presumably reinvite) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 0: INVITE sip:0215890000@10.105.177.14:5060 SIP/2.0 (48) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 1: Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK1498562f (58) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 2: From: "0315400414" ;tag=as5edcbb80 (64) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 3: To: ;tag=995d84911a7d552 (54) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 4: Contact: (39) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 5: Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 (55) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 6: CSeq: 103 INVITE (16) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 8: Max-Forwards: 70 (16) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 10: Supported: replaces (19) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 12: Content-Type: application/sdp (29) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 13: Content-Length: 184 (19) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4639 parse_request: Header 14: (0) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: v=0 (3) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: o=root 5302 5304 IN IP4 10.105.177.21 (37) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: s=session (9) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: c=IN IP4 10.105.177.21 (22) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: t=0 0 (5) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: m=audio 19516 RTP/AVP 8 (23) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=silenceSupp:off - - - - (25) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=ptime:20 (10) [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:4671 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 10.105.177.14:5060: INVITE sip:0215890000@10.105.177.14:5060 SIP/2.0 Via: SIP/2.0/UDP 10.105.177.21:5060;branch=z9hG4bK1498562f From: "0315400414" ;tag=as5edcbb80 To: ;tag=995d84911a7d552 Contact: Call-ID: 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21 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: 184 v=0 o=root 5302 5304 IN IP4 10.105.177.21 s=session c=IN IP4 10.105.177.21 t=0 0 m=audio 19516 RTP/AVP 8 a=rtpmap:8 PCMA/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:2017 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #277305 [Aug 17 18:23:26] DEBUG[9980]: channel.c:4227 ast_channel_bridge: Returning from native bridge, channels: SIP/10.36.2.1-009531d0, SIP/patton-007fdfe0 [Aug 17 18:23:26] DEBUG[9980]: channel.c:1759 ast_hangup: Hanging up channel 'SIP/patton-007fdfe0' [Aug 17 18:23:26] DEBUG[9980]: chan_sip.c:3367 sip_hangup: Hangup call SIP/patton-007fdfe0, SIP callid 2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21) Scheduling destruction of SIP dialog '2a8d02d44f867e9d2cd74ca600e6a28e@10.105.177.21' in 6400 ms (Method: ACK) [Aug 17 18:23:26] DEBUG[9980]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/patton-007fdfe0 [Aug 17 18:23:26] DEBUG[9980]: rtp.c:1499 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything [Aug 17 18:23:26] DEBUG[9980]: app_dial.c:1686 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Aug 17 18:23:26] DEBUG[9980]: pbx.c:2409 __ast_pbx_run: Spawn extension (world,0215890000,1) exited non-zero on 'SIP/10.36.2.1-009531d0'