[May 24 12:35:16] VERBOSE[4288] asterisk.c: Asterisk Ready. [May 24 12:35:44] DEBUG[4301] chan_dahdi.c: Monitor doohicky got event Ring Begin on channel 2 [May 24 12:35:44] DEBUG[4301] sig_analog.c: channel (2) - signaling (5) - event (ANALOG_EVENT_RINGBEGIN) [May 24 12:35:46] DEBUG[4301] chan_dahdi.c: Monitor doohicky got event Ring/Answered on channel 2 [May 24 12:35:46] DEBUG[4301] sig_analog.c: channel (2) - signaling (5) - event (ANALOG_EVENT_RINGOFFHOOK) [May 24 12:35:46] DEBUG[4301] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [May 24 12:35:46] DEBUG[4301] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [May 24 12:35:46] DEBUG[4301] devicestate.c: device 'DAHDI/2-1' state '2' [May 24 12:35:46] DEBUG[4308] sig_analog.c: __analog_ss_thread 2 [May 24 12:35:46] VERBOSE[4308] sig_analog.c: -- Starting simple switch on 'DAHDI/2-1' [May 24 12:35:47] DEBUG[4308] chan_dahdi.c: CallerID number: 4258916962, name: BRANDLI STEVE , flags=0 [May 24 12:35:47] DEBUG[4308] pbx.c: Launching 'Answer' [May 24 12:35:47] VERBOSE[4308] pbx.c: -- Executing [s@external:1] Answer("DAHDI/2-1", "") in new stack [May 24 12:35:47] DEBUG[4308] sig_analog.c: analog_answer 2 [May 24 12:35:47] DEBUG[4308] sig_analog.c: Took DAHDI/2-1 off hook [May 24 12:35:47] DEBUG[4308] chan_dahdi.c: Enabled echo cancellation on channel 2 [May 24 12:35:47] DEBUG[4308] chan_dahdi.c: No echo training requested [May 24 12:35:47] DEBUG[4308] chan_dahdi.c: Requested indication -1 on channel DAHDI/2-1 [May 24 12:35:47] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for DAHDI - 2 [May 24 12:35:47] DEBUG[4293] devicestate.c: Changing state for DAHDI/2 - state 2 (In use) [May 24 12:35:47] DEBUG[4293] devicestate.c: device 'DAHDI/2' state '2' [May 24 12:35:47] DEBUG[4308] pbx.c: Function result is '0' [May 24 12:35:47] DEBUG[4308] pbx.c: Expression result is '0' [May 24 12:35:47] DEBUG[4308] pbx.c: Launching 'GotoIf' [May 24 12:35:47] VERBOSE[4308] pbx.c: -- Executing [s@external:2] GotoIf("DAHDI/2-1", "0?closed,s,1") in new stack [May 24 12:35:47] DEBUG[4308] pbx.c: Not taking any branch [May 24 12:35:47] DEBUG[4308] pbx.c: Launching 'Dial' [May 24 12:35:47] VERBOSE[4308] pbx.c: -- Executing [s@external:3] Dial("DAHDI/2-1", "SIP/61&SIP/63&SIP/65,15,t") in new stack [May 24 12:35:47] DEBUG[4308] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: Allocating new SIP dialog for 1c68e09932587a867175d4c320f68f50@192.168.136.15:0 - INVITE (No RTP) [May 24 12:35:47] DEBUG[4308] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9fa6338' [May 24 12:35:47] DEBUG[4308] res_rtp_asterisk.c: Allocated port 11848 for RTP instance '0x9fa6338' [May 24 12:35:47] DEBUG[4308] rtp_engine.c: RTP instance '0x9fa6338' is setup and ready to go [May 24 12:35:47] DEBUG[4308] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9fa6338' [May 24 12:35:47] VERBOSE[4308] netsock2.c: == Using SIP RTP CoS mark 5 [May 24 12:35:47] DEBUG[4308] chan_sip.c: Setting NAT on RTP to Off [May 24 12:35:47] DEBUG[4308] acl.c: For destination '192.168.77.55', our source address is '192.168.77.20'. [May 24 12:35:47] DEBUG[4308] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.77.20:5060 [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Our native formats are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Our capabilities are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: This channel will not be able to handle video. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALEDTIME. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable ANSWEREDTIME. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALEDPEERNAME. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALEDPEERNUMBER. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALSTATUS. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DB_RESULT. [May 24 12:35:47] DEBUG[4308] chan_sip.c: Outgoing Call for 61 [May 24 12:35:47] DEBUG[4308] chan_sip.c: Updating call counter for outgoing call [May 24 12:35:47] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:35:47] DEBUG[4308] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: False Text flag: False [May 24 12:35:47] DEBUG[4308] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: -- Done with adding codecs to SDP [May 24 12:35:47] DEBUG[4308] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: Initializing initreq for method INVITE - callid 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 [May 24 12:35:47] DEBUG[4308] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:35:47] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:35:47] VERBOSE[4308] app_dial.c: -- Called 61 [May 24 12:35:47] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 6 (Ringing) [May 24 12:35:47] DEBUG[4308] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: Allocating new SIP dialog for 59badde7041e09fc475d9e29231edfc1@192.168.136.15:0 - INVITE (No RTP) [May 24 12:35:47] DEBUG[4308] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9fbe988' [May 24 12:35:47] DEBUG[4308] res_rtp_asterisk.c: Allocated port 12232 for RTP instance '0x9fbe988' [May 24 12:35:47] DEBUG[4308] rtp_engine.c: RTP instance '0x9fbe988' is setup and ready to go [May 24 12:35:47] DEBUG[4308] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9fbe988' [May 24 12:35:47] VERBOSE[4308] netsock2.c: == Using SIP RTP CoS mark 5 [May 24 12:35:47] DEBUG[4308] chan_sip.c: Setting NAT on RTP to Off [May 24 12:35:47] DEBUG[4308] acl.c: For destination '192.168.77.53', our source address is '192.168.77.20'. [May 24 12:35:47] DEBUG[4308] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.77.20:5060 [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Our native formats are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Our capabilities are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: This channel will not be able to handle video. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALEDTIME. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable ANSWEREDTIME. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALEDPEERNAME. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALEDPEERNUMBER. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALSTATUS. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DB_RESULT. [May 24 12:35:47] DEBUG[4308] chan_sip.c: Outgoing Call for 63 [May 24 12:35:47] DEBUG[4308] chan_sip.c: Updating call counter for outgoing call [May 24 12:35:47] DEBUG[4308] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: False Text flag: False [May 24 12:35:47] DEBUG[4308] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: -- Done with adding codecs to SDP [May 24 12:35:47] DEBUG[4308] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: Initializing initreq for method INVITE - callid 3897f9d2678d90e76f69989922910867@192.168.77.20:5060 [May 24 12:35:47] DEBUG[4293] devicestate.c: device 'SIP/61' state '6' [May 24 12:35:47] DEBUG[4308] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.77.53:5060 [May 24 12:35:47] VERBOSE[4308] app_dial.c: -- Called 63 [May 24 12:35:47] DEBUG[4308] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: Allocating new SIP dialog for 041f4bdb0764fc914f9eb1591d5f7800@192.168.136.15:0 - INVITE (No RTP) [May 24 12:35:47] DEBUG[4308] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb7dbea88' [May 24 12:35:47] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 63 [May 24 12:35:47] DEBUG[4293] chan_sip.c: Checking device state for peer 63 [May 24 12:35:47] DEBUG[4293] devicestate.c: Changing state for SIP/63 - state 6 (Ringing) [May 24 12:35:47] DEBUG[4293] devicestate.c: device 'SIP/63' state '6' [May 24 12:35:47] DEBUG[4308] res_rtp_asterisk.c: Allocated port 27836 for RTP instance '0xb7dbea88' [May 24 12:35:47] DEBUG[4308] rtp_engine.c: RTP instance '0xb7dbea88' is setup and ready to go [May 24 12:35:47] DEBUG[4308] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb7dbea88' [May 24 12:35:47] VERBOSE[4308] netsock2.c: == Using SIP RTP CoS mark 5 [May 24 12:35:47] DEBUG[4308] chan_sip.c: Setting NAT on RTP to Off [May 24 12:35:47] DEBUG[4308] acl.c: For destination '192.168.77.51', our source address is '192.168.77.20'. [May 24 12:35:47] DEBUG[4308] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.77.20:5060 [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Our native formats are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Our capabilities are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: This channel will not be able to handle video. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALEDTIME. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable ANSWEREDTIME. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALEDPEERNAME. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALEDPEERNUMBER. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DIALSTATUS. [May 24 12:35:47] DEBUG[4308] channel.c: Not copying variable DB_RESULT. [May 24 12:35:47] DEBUG[4308] chan_sip.c: Outgoing Call for 65 [May 24 12:35:47] DEBUG[4308] chan_sip.c: Updating call counter for outgoing call [May 24 12:35:47] DEBUG[4308] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: False Text flag: False [May 24 12:35:47] DEBUG[4308] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: -- Done with adding codecs to SDP [May 24 12:35:47] DEBUG[4308] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [May 24 12:35:47] DEBUG[4308] chan_sip.c: Initializing initreq for method INVITE - callid 639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060 [May 24 12:35:47] DEBUG[4308] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.77.51:5060 [May 24 12:35:47] VERBOSE[4308] app_dial.c: -- Called 65 [May 24 12:35:47] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 65 [May 24 12:35:47] DEBUG[4293] chan_sip.c: Checking device state for peer 65 [May 24 12:35:47] DEBUG[4293] devicestate.c: Changing state for SIP/65 - state 6 (Ringing) [May 24 12:35:47] DEBUG[4293] devicestate.c: device 'SIP/65' state '6' [May 24 12:35:47] DEBUG[4300] chan_sip.c: = Looking for Call ID: 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 (Checking To) --From tag as0d862500 --To-tag E74FF351-615ED192 [May 24 12:35:47] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060' Request 102: Found [May 24 12:35:47] DEBUG[4300] chan_sip.c: SIP response 100 to standard invite [May 24 12:35:47] DEBUG[4300] chan_sip.c: = Looking for Call ID: 639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060 (Checking To) --From tag as62315ca8 --To-tag 13D51CD-16C87C0E [May 24 12:35:47] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060' Request 102: Found [May 24 12:35:47] DEBUG[4300] chan_sip.c: SIP response 100 to standard invite [May 24 12:35:47] DEBUG[4300] chan_sip.c: = Looking for Call ID: 3897f9d2678d90e76f69989922910867@192.168.77.20:5060 (Checking To) --From tag as77e72693 --To-tag 3D3486BA-C8BE77BD [May 24 12:35:47] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3897f9d2678d90e76f69989922910867@192.168.77.20:5060' Request 102: Found [May 24 12:35:47] DEBUG[4300] chan_sip.c: SIP response 100 to standard invite [May 24 12:35:47] DEBUG[4300] chan_sip.c: = Looking for Call ID: 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 (Checking To) --From tag as0d862500 --To-tag E74FF351-615ED192 [May 24 12:35:47] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060' Request 102: Found [May 24 12:35:47] DEBUG[4300] chan_sip.c: SIP response 180 to standard invite [May 24 12:35:47] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:35:47] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:35:47] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 6 (Ringing) [May 24 12:35:47] DEBUG[4293] devicestate.c: device 'SIP/61' state '6' [May 24 12:35:47] VERBOSE[4308] app_dial.c: -- SIP/61-00000000 is ringing [May 24 12:35:47] DEBUG[4308] chan_dahdi.c: Requested indication 3 on channel DAHDI/2-1 [May 24 12:35:47] DEBUG[4300] chan_sip.c: = Looking for Call ID: 639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060 (Checking To) --From tag as62315ca8 --To-tag 13D51CD-16C87C0E [May 24 12:35:47] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060' Request 102: Found [May 24 12:35:47] DEBUG[4300] chan_sip.c: SIP response 180 to standard invite [May 24 12:35:47] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 65 [May 24 12:35:47] DEBUG[4293] chan_sip.c: Checking device state for peer 65 [May 24 12:35:47] DEBUG[4293] devicestate.c: Changing state for SIP/65 - state 6 (Ringing) [May 24 12:35:47] DEBUG[4293] devicestate.c: device 'SIP/65' state '6' [May 24 12:35:47] VERBOSE[4308] app_dial.c: -- SIP/65-00000002 is ringing [May 24 12:35:47] DEBUG[4300] chan_sip.c: = Looking for Call ID: 3897f9d2678d90e76f69989922910867@192.168.77.20:5060 (Checking To) --From tag as77e72693 --To-tag 3D3486BA-C8BE77BD [May 24 12:35:47] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3897f9d2678d90e76f69989922910867@192.168.77.20:5060' Request 102: Found [May 24 12:35:47] DEBUG[4300] chan_sip.c: SIP response 180 to standard invite [May 24 12:35:47] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 63 [May 24 12:35:47] DEBUG[4293] chan_sip.c: Checking device state for peer 63 [May 24 12:35:47] DEBUG[4293] devicestate.c: Changing state for SIP/63 - state 6 (Ringing) [May 24 12:35:47] DEBUG[4293] devicestate.c: device 'SIP/63' state '6' [May 24 12:35:47] VERBOSE[4308] app_dial.c: -- SIP/63-00000001 is ringing [May 24 12:35:48] DEBUG[4300] chan_sip.c: = Looking for Call ID: 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 (Checking To) --From tag as0d862500 --To-tag E74FF351-615ED192 [May 24 12:35:48] DEBUG[4300] chan_sip.c: Acked pending invite 102 [May 24 12:35:48] DEBUG[4300] chan_sip.c: Stopping retransmission on '59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060' of Request 102: Match Found [May 24 12:35:48] DEBUG[4300] chan_sip.c: SIP response 200 to standard invite [May 24 12:35:48] DEBUG[4300] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 24 12:35:48] DEBUG[4300] chan_sip.c: Processing session-level SDP o=- 1306265734 1306265734 IN IP4 192.168.77.55... UNSUPPORTED. [May 24 12:35:48] DEBUG[4300] chan_sip.c: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED. [May 24 12:35:48] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:35:48] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:35:48] DEBUG[4300] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.77.55... OK. [May 24 12:35:48] DEBUG[4300] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 24 12:35:48] DEBUG[4300] rtp_engine.c: Setting payload 0 based on m type on 0xb7b594fc [May 24 12:35:48] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [May 24 12:35:48] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 24 12:35:48] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:127 telephone-event/8000... OK. [May 24 12:35:48] DEBUG[4300] rtp_engine.c: Incorporating payload 0 on 0xb7b594fc [May 24 12:35:48] DEBUG[4300] rtp_engine.c: Incorporating payload 127 on 0xb7b594fc [May 24 12:35:48] DEBUG[4300] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fa6338' [May 24 12:35:48] DEBUG[4300] rtp_engine.c: Copying payload 0 from 0xb7b594fc to 0x9fa64e4 [May 24 12:35:48] DEBUG[4300] rtp_engine.c: Copying payload 127 from 0xb7b594fc to 0x9fa64e4 [May 24 12:35:48] DEBUG[4300] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [May 24 12:35:48] DEBUG[4300] chan_sip.c: We have an owner, now see if we need to change this call [May 24 12:35:48] DEBUG[4300] chan_sip.c: Updating call counter for outgoing call [May 24 12:35:48] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:35:48] DEBUG[4300] chan_sip.c: build_route: Contact hop: [May 24 12:35:48] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:35:48] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:35:48] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:35:48] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:35:48] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:35:48] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:35:48] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:35:48] DEBUG[4300] chan_sip.c: Trying to put 'ACK sip:61@' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:35:48] VERBOSE[4308] app_dial.c: -- SIP/61-00000000 connected line has changed. Saving it until answer for DAHDI/2-1 [May 24 12:35:48] VERBOSE[4308] app_dial.c: -- SIP/61-00000000 answered DAHDI/2-1 [May 24 12:35:48] DEBUG[4308] chan_dahdi.c: Requested indication 22 on channel DAHDI/2-1 [May 24 12:35:48] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:35:48] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:35:48] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:35:48] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:35:48] DEBUG[4308] channel.c: Hanging up channel 'SIP/65-00000002' [May 24 12:35:48] DEBUG[4308] chan_sip.c: This call was answered elsewhere[May 24 12:35:48] DEBUG[4308] chan_sip.c: ####### It's the cause code, buddy. The cause code!!! [May 24 12:35:48] DEBUG[4308] chan_sip.c: Hangup call SIP/65-00000002, SIP callid 639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060 [May 24 12:35:48] DEBUG[4308] chan_sip.c: Updating call counter for outgoing call [May 24 12:35:48] DEBUG[4308] chan_sip.c: Hanging up channel in state Ringing (not UP) [May 24 12:35:48] DEBUG[4308] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb7dbea88' [May 24 12:35:48] DEBUG[4308] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060' Request 102: Found [May 24 12:35:48] DEBUG[4308] chan_sip.c: Trying to put 'CANCEL sip:' onto UDP socket destined for 192.168.77.51:5060 [May 24 12:35:48] DEBUG[4308] channel.c: Hanging up channel 'SIP/63-00000001' [May 24 12:35:48] DEBUG[4308] chan_sip.c: This call was answered elsewhere[May 24 12:35:48] DEBUG[4308] chan_sip.c: ####### It's the cause code, buddy. The cause code!!! [May 24 12:35:48] DEBUG[4308] chan_sip.c: Hangup call SIP/63-00000001, SIP callid 3897f9d2678d90e76f69989922910867@192.168.77.20:5060 [May 24 12:35:48] DEBUG[4308] chan_sip.c: Updating call counter for outgoing call [May 24 12:35:48] DEBUG[4308] chan_sip.c: Hanging up channel in state Ringing (not UP) [May 24 12:35:48] DEBUG[4308] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fbe988' [May 24 12:35:48] DEBUG[4308] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3897f9d2678d90e76f69989922910867@192.168.77.20:5060' Request 102: Found [May 24 12:35:48] DEBUG[4308] chan_sip.c: Trying to put 'CANCEL sip:' onto UDP socket destined for 192.168.77.53:5060 [May 24 12:35:48] DEBUG[4308] features.c: bridge answer set, chan answer set [May 24 12:35:48] DEBUG[4308] chan_dahdi.c: Requested indication 20 on channel DAHDI/2-1 [May 24 12:35:48] DEBUG[4308] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 24 12:35:48] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 65 [May 24 12:35:48] DEBUG[4293] chan_sip.c: Checking device state for peer 65 [May 24 12:35:48] DEBUG[4293] devicestate.c: Changing state for SIP/65 - state 1 (Not in use) [May 24 12:35:48] DEBUG[4293] devicestate.c: device 'SIP/65' state '1' [May 24 12:35:48] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 65 [May 24 12:35:48] DEBUG[4293] chan_sip.c: Checking device state for peer 65 [May 24 12:35:48] DEBUG[4293] devicestate.c: Changing state for SIP/65 - state 1 (Not in use) [May 24 12:35:48] DEBUG[4293] devicestate.c: device 'SIP/65' state '1' [May 24 12:35:48] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 63 [May 24 12:35:48] DEBUG[4293] chan_sip.c: Checking device state for peer 63 [May 24 12:35:48] DEBUG[4293] devicestate.c: Changing state for SIP/63 - state 1 (Not in use) [May 24 12:35:48] DEBUG[4293] devicestate.c: device 'SIP/63' state '1' [May 24 12:35:48] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 63 [May 24 12:35:48] DEBUG[4293] chan_sip.c: Checking device state for peer 63 [May 24 12:35:48] DEBUG[4293] devicestate.c: Changing state for SIP/63 - state 1 (Not in use) [May 24 12:35:48] DEBUG[4293] devicestate.c: device 'SIP/63' state '1' [May 24 12:35:48] DEBUG[4308] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [May 24 12:35:48] DEBUG[4308] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [May 24 12:35:48] DEBUG[4308] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x9fa6338' [May 24 12:35:48] DEBUG[4300] chan_sip.c: = Looking for Call ID: 639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060 (Checking To) --From tag as62315ca8 --To-tag [May 24 12:35:48] DEBUG[4300] chan_sip.c: Acked pending invite 102 [May 24 12:35:48] DEBUG[4300] chan_sip.c: Stopping retransmission on '639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060' of Request 102: Match Found [May 24 12:35:48] DEBUG[4300] chan_sip.c: = Looking for Call ID: 3897f9d2678d90e76f69989922910867@192.168.77.20:5060 (Checking To) --From tag as77e72693 --To-tag [May 24 12:35:48] DEBUG[4300] chan_sip.c: Acked pending invite 102 [May 24 12:35:48] DEBUG[4300] chan_sip.c: Stopping retransmission on '3897f9d2678d90e76f69989922910867@192.168.77.20:5060' of Request 102: Match Found [May 24 12:35:48] DEBUG[4300] chan_sip.c: = Looking for Call ID: 639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060 (Checking To) --From tag as62315ca8 --To-tag 13D51CD-16C87C0E [May 24 12:35:48] DEBUG[4300] chan_sip.c: Stopping retransmission on '639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060' of Request 102: Match Found [May 24 12:35:48] DEBUG[4300] chan_sip.c: SIP response 487 to standard invite [May 24 12:35:48] DEBUG[4300] chan_sip.c: Trying to put 'ACK sip:65@' onto UDP socket destined for 192.168.77.51:5060 [May 24 12:35:48] DEBUG[4300] chan_sip.c: Updating call counter for outgoing call [May 24 12:35:48] DEBUG[4300] chan_sip.c: Setting SIP_ALREADYGONE on dialog 639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060 [May 24 12:35:48] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 65 [May 24 12:35:48] DEBUG[4300] chan_sip.c: Destroying SIP dialog 639842d63bd8132e0f9d0bcd22285e4b@192.168.77.20:5060 [May 24 12:35:48] DEBUG[4293] chan_sip.c: Checking device state for peer 65 [May 24 12:35:48] DEBUG[4293] devicestate.c: Changing state for SIP/65 - state 1 (Not in use) [May 24 12:35:48] DEBUG[4293] devicestate.c: device 'SIP/65' state '1' [May 24 12:35:48] DEBUG[4300] rtp_engine.c: Destroyed RTP instance '0xb7dbea88' [May 24 12:35:48] DEBUG[4300] chan_sip.c: = Looking for Call ID: 3897f9d2678d90e76f69989922910867@192.168.77.20:5060 (Checking To) --From tag as77e72693 --To-tag 3D3486BA-C8BE77BD [May 24 12:35:48] DEBUG[4300] chan_sip.c: Stopping retransmission on '3897f9d2678d90e76f69989922910867@192.168.77.20:5060' of Request 102: Match Found [May 24 12:35:48] DEBUG[4300] chan_sip.c: SIP response 487 to standard invite [May 24 12:35:48] DEBUG[4300] chan_sip.c: Trying to put 'ACK sip:63@' onto UDP socket destined for 192.168.77.53:5060 [May 24 12:35:48] DEBUG[4300] chan_sip.c: Updating call counter for outgoing call [May 24 12:35:48] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 63 [May 24 12:35:48] DEBUG[4293] chan_sip.c: Checking device state for peer 63 [May 24 12:35:48] DEBUG[4293] devicestate.c: Changing state for SIP/63 - state 1 (Not in use) [May 24 12:35:48] DEBUG[4293] devicestate.c: device 'SIP/63' state '1' [May 24 12:35:48] DEBUG[4300] chan_sip.c: Setting SIP_ALREADYGONE on dialog 3897f9d2678d90e76f69989922910867@192.168.77.20:5060 [May 24 12:35:48] DEBUG[4300] chan_sip.c: Destroying SIP dialog 3897f9d2678d90e76f69989922910867@192.168.77.20:5060 [May 24 12:35:48] DEBUG[4300] rtp_engine.c: Destroyed RTP instance '0x9fbe988' [May 24 12:35:49] DEBUG[4300] chan_sip.c: = Looking for Call ID: 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 (Checking From) --From tag E74FF351-615ED192 --To-tag as0d862500 [May 24 12:35:49] DEBUG[4300] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 24 12:35:49] DEBUG[4300] sip/reqresp_parser.c: Begin: parsing SIP "Supported: 100rel,replaces" [May 24 12:35:49] DEBUG[4300] sip/reqresp_parser.c: Found SIP option: -100rel- [May 24 12:35:49] DEBUG[4300] sip/reqresp_parser.c: Matched SIP option: 100rel [May 24 12:35:49] DEBUG[4300] sip/reqresp_parser.c: Found SIP option: -replaces- [May 24 12:35:49] DEBUG[4300] sip/reqresp_parser.c: Matched SIP option: replaces [May 24 12:35:49] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:35:49] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:35:49] DEBUG[4300] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 24 12:35:49] DEBUG[4300] chan_sip.c: Processing session-level SDP o=- 1306265734 1306265735 IN IP4 192.168.77.55... UNSUPPORTED. [May 24 12:35:49] DEBUG[4300] chan_sip.c: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED. [May 24 12:35:49] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:35:49] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:35:49] DEBUG[4300] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.77.55... OK. [May 24 12:35:49] DEBUG[4300] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 24 12:35:49] DEBUG[4300] chan_sip.c: Processing session-level SDP a=sendonly... OK. [May 24 12:35:49] DEBUG[4300] rtp_engine.c: Setting payload 0 based on m type on 0xb7b5939c [May 24 12:35:49] DEBUG[4300] rtp_engine.c: Setting payload 101 based on m type on 0xb7b5939c [May 24 12:35:49] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=sendonly... OK. [May 24 12:35:49] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 24 12:35:49] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 24 12:35:49] DEBUG[4300] rtp_engine.c: Incorporating payload 0 on 0xb7b5939c [May 24 12:35:49] DEBUG[4300] rtp_engine.c: Incorporating payload 101 on 0xb7b5939c [May 24 12:35:49] DEBUG[4300] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fa6338' [May 24 12:35:49] DEBUG[4300] rtp_engine.c: Copying payload 0 from 0xb7b5939c to 0x9fa64e4 [May 24 12:35:49] DEBUG[4300] rtp_engine.c: Copying payload 101 from 0xb7b5939c to 0x9fa64e4 [May 24 12:35:49] DEBUG[4300] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [May 24 12:35:49] DEBUG[4300] chan_sip.c: We have an owner, now see if we need to change this call [May 24 12:35:49] DEBUG[4300] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fa6338' [May 24 12:35:49] DEBUG[4300] chan_sip.c: SIP/61-00000000: This call is UP.... [May 24 12:35:49] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:35:49] DEBUG[4300] chan_sip.c: Setting framing from config on incoming call [May 24 12:35:49] DEBUG[4300] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True Text flag: True [May 24 12:35:49] DEBUG[4300] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [May 24 12:35:49] DEBUG[4300] chan_sip.c: -- Done with adding codecs to SDP [May 24 12:35:49] DEBUG[4300] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [May 24 12:35:49] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:35:49] DEBUG[4308] chan_dahdi.c: Requested indication 16 on channel DAHDI/2-1 [May 24 12:35:49] VERBOSE[4308] channel.c: -- Music class default requested but no musiconhold loaded. [May 24 12:35:49] DEBUG[4308] chan_dahdi.c: Requested indication 20 on channel DAHDI/2-1 [May 24 12:35:49] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:49] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:49] DEBUG[4300] chan_sip.c: = Looking for Call ID: 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 (Checking From) --From tag E74FF351-615ED192 --To-tag as0d862500 [May 24 12:35:49] DEBUG[4300] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 24 12:35:49] DEBUG[4300] chan_sip.c: Stopping retransmission on '59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060' of Response 1: Match Found [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4300] chan_sip.c: = Looking for Call ID: a8efdd04-fcc48d-1043aa6e@192.168.77.55 (Checking From) --From tag 59F6CB50-DA67CBF9 --To-tag [May 24 12:35:50] DEBUG[4300] acl.c: For destination '192.168.77.55', our source address is '192.168.77.20'. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.77.20:5060 [May 24 12:35:50] DEBUG[4300] chan_sip.c: Allocating new SIP dialog for a8efdd04-fcc48d-1043aa6e@192.168.77.55 - INVITE (No RTP) [May 24 12:35:50] DEBUG[4300] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 24 12:35:50] DEBUG[4300] sip/reqresp_parser.c: Begin: parsing SIP "Supported: 100rel,replaces" [May 24 12:35:50] DEBUG[4300] sip/reqresp_parser.c: Found SIP option: -100rel- [May 24 12:35:50] DEBUG[4300] sip/reqresp_parser.c: Matched SIP option: 100rel [May 24 12:35:50] DEBUG[4300] sip/reqresp_parser.c: Found SIP option: -replaces- [May 24 12:35:50] DEBUG[4300] sip/reqresp_parser.c: Matched SIP option: replaces [May 24 12:35:50] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:35:50] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:35:50] DEBUG[4300] chan_sip.c: = Looking for Call ID: a8efdd04-fcc48d-1043aa6e@192.168.77.55 (Checking From) --From tag 59F6CB50-DA67CBF9 --To-tag as33a00290 [May 24 12:35:50] DEBUG[4300] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 24 12:35:50] DEBUG[4300] chan_sip.c: Stopping retransmission on 'a8efdd04-fcc48d-1043aa6e@192.168.77.55' of Response 1: Match Found [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:50] DEBUG[4300] chan_sip.c: = Looking for Call ID: a8efdd04-fcc48d-1043aa6e@192.168.77.55 (Checking From) --From tag 59F6CB50-DA67CBF9 --To-tag [May 24 12:35:50] DEBUG[4300] netsock2.c: Splitting '192.168.77.20' gives... [May 24 12:35:50] DEBUG[4300] netsock2.c: ...host '192.168.77.20' and port '(null)'. [May 24 12:35:50] DEBUG[4300] netsock2.c: Splitting '192.168.77.20' gives... [May 24 12:35:50] DEBUG[4300] netsock2.c: ...host '192.168.77.20' and port '(null)'. [May 24 12:35:50] DEBUG[4300] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 24 12:35:50] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:35:50] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9fbb1d8' [May 24 12:35:50] DEBUG[4300] res_rtp_asterisk.c: Allocated port 20796 for RTP instance '0x9fbb1d8' [May 24 12:35:50] DEBUG[4300] rtp_engine.c: RTP instance '0x9fbb1d8' is setup and ready to go [May 24 12:35:50] DEBUG[4300] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9fbb1d8' [May 24 12:35:50] VERBOSE[4300] netsock2.c: == Using SIP RTP CoS mark 5 [May 24 12:35:50] DEBUG[4300] chan_sip.c: Setting NAT on RTP to Off [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing session-level SDP o=- 1306265736 1306265736 IN IP4 192.168.77.55... UNSUPPORTED. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED. [May 24 12:35:50] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:35:50] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.77.55... OK. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing session-level SDP a=sendrecv... OK. [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Setting payload 9 based on m type on 0xb7b5939c [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Setting payload 0 based on m type on 0xb7b5939c [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Setting payload 8 based on m type on 0xb7b5939c [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Setting payload 18 based on m type on 0xb7b5939c [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED. [May 24 12:35:50] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:127 telephone-event/8000... OK. [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Incorporating payload 0 on 0xb7b5939c [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Incorporating payload 8 on 0xb7b5939c [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Incorporating payload 9 on 0xb7b5939c [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Incorporating payload 18 on 0xb7b5939c [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Incorporating payload 127 on 0xb7b5939c [May 24 12:35:50] DEBUG[4300] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fbb1d8' [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Copying payload 0 from 0xb7b5939c to 0x9fbb384 [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Copying payload 8 from 0xb7b5939c to 0x9fbb384 [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Copying payload 9 from 0xb7b5939c to 0x9fbb384 [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Copying payload 18 from 0xb7b5939c to 0x9fbb384 [May 24 12:35:50] DEBUG[4300] rtp_engine.c: Copying payload 127 from 0xb7b5939c to 0x9fbb384 [May 24 12:35:50] DEBUG[4300] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [May 24 12:35:50] DEBUG[4300] chan_sip.c: Checking SIP call limits for device 61 [May 24 12:35:50] DEBUG[4300] chan_sip.c: Updating call counter for incoming call [May 24 12:35:50] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:35:50] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:35:50] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:35:50] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:35:50] DEBUG[4300] chan_sip.c: *** Our native formats are 0x4 (ulaw) [May 24 12:35:50] DEBUG[4300] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [May 24 12:35:50] DEBUG[4300] chan_sip.c: *** Our capabilities are 0x4 (ulaw) [May 24 12:35:50] DEBUG[4300] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [May 24 12:35:50] DEBUG[4300] chan_sip.c: This channel will not be able to handle video. [May 24 12:35:50] DEBUG[4300] chan_sip.c: build_route: Contact hop: [May 24 12:35:50] DEBUG[4300] chan_sip.c: SIP/61-00000003: New call is still down.... Trying... [May 24 12:35:50] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:35:50] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:35:50] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:35:50] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:35:50] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:35:50] DEBUG[4309] pbx.c: Launching 'Set' [May 24 12:35:50] VERBOSE[4309] pbx.c: -- Executing [26@internal:1] Set("SIP/61-00000003", "CONFBRIDGE_JOIN_SOUND=en/beep") in new stack [May 24 12:35:50] DEBUG[4309] pbx.c: Launching 'Set' [May 24 12:35:50] VERBOSE[4309] pbx.c: -- Executing [26@internal:2] Set("SIP/61-00000003", "CONFBRIDGE_LEAVE_SOUND=en/beep") in new stack [May 24 12:35:50] DEBUG[4309] pbx.c: Launching 'Answer' [May 24 12:35:50] VERBOSE[4309] pbx.c: -- Executing [26@internal:3] Answer("SIP/61-00000003", "") in new stack [May 24 12:35:50] DEBUG[4309] chan_sip.c: SIP answering channel: SIP/61-00000003 [May 24 12:35:50] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:35:50] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:35:50] DEBUG[4309] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 24 12:35:50] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:35:50] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:35:50] DEBUG[4309] chan_sip.c: Setting framing from config on incoming call [May 24 12:35:50] DEBUG[4309] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True Text flag: True [May 24 12:35:50] DEBUG[4309] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [May 24 12:35:50] DEBUG[4309] chan_sip.c: -- Done with adding codecs to SDP [May 24 12:35:50] DEBUG[4309] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [May 24 12:35:50] DEBUG[4309] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:35:50] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4300] chan_sip.c: = Looking for Call ID: a8efdd04-fcc48d-1043aa6e@192.168.77.55 (Checking From) --From tag 59F6CB50-DA67CBF9 --To-tag as1eb33679 [May 24 12:35:51] DEBUG[4300] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 24 12:35:51] DEBUG[4300] chan_sip.c: Stopping retransmission on 'a8efdd04-fcc48d-1043aa6e@192.168.77.55' of Response 2: Match Found [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4309] pbx.c: Launching 'ConfBridge' [May 24 12:35:51] VERBOSE[4309] pbx.c: -- Executing [26@internal:4] ConfBridge("SIP/61-00000003", "26,1s") in new stack [May 24 12:35:51] DEBUG[4309] app_confbridge.c: Trying to find conference bridge '26' [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge technology softmix has capabilities 0x34 (ulaw|adpcm|g726aal2) and we want 0x4 (ulaw) [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge technology simple_bridge has capabilities 0x22 (gsm|adpcm) and we want 0x4 (ulaw) [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge technology simple_bridge does not have the capabilities we need. [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge technology multiplexed_bridge has capabilities 0x2 (gsm) and we want 0x4 (ulaw) [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge technology multiplexed_bridge does not have the capabilities we need. [May 24 12:35:51] DEBUG[4309] bridging.c: Chose bridge technology softmix [May 24 12:35:51] DEBUG[4309] bridging.c: Giving bridge technology softmix the bridge structure 0x9fb8038 to setup [May 24 12:35:51] DEBUG[4309] bridging.c: Telling all channels in bridge 0x9fb8038 to end and leave the party [May 24 12:35:51] DEBUG[4309] bridging.c: Actually destroying bridge 0x9fb8038, nobody wants it anymore [May 24 12:35:51] DEBUG[4309] bridging.c: Giving bridge technology softmix the bridge structure 0x9fb8038 to destroy [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge technology softmix has capabilities 0x34 (ulaw|adpcm|g726aal2) and we want 0x2 (gsm) [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge technology softmix does not have the capabilities we need. [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge technology simple_bridge has capabilities 0x22 (gsm|adpcm) and we want 0x2 (gsm) [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge technology multiplexed_bridge has capabilities 0x2 (gsm) and we want 0x2 (gsm) [May 24 12:35:51] DEBUG[4309] bridging.c: Chose bridge technology multiplexed_bridge [May 24 12:35:51] DEBUG[4309] bridging.c: Giving bridge technology multiplexed_bridge the bridge structure 0xb7dbdb20 to setup [May 24 12:35:51] DEBUG[4309] bridge_multiplexed.c: Created multiplexed thread '0xb7dbdb90' for bridge '0xb7dbdb20' [May 24 12:35:51] DEBUG[4309] app_confbridge.c: Created conference bridge '26' and linked to container '0x9f76d80' [May 24 12:35:51] DEBUG[4309] devicestate.c: device 'confbridge:26' state '2' [May 24 12:35:51] DEBUG[4309] bridging.c: Joining bridge channel 0xb79b2998 to bridge 0xb7dbdb20 [May 24 12:35:51] DEBUG[4309] bridging.c: Added channel SIP/61-00000003(0x9fc8bb8) to bridge array on 0xb7dbdb20, new count is 1 [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge 0xb7dbdb20 channel count (1) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge 0xb7dbdb20 is happy that channel SIP/61-00000003 already has read format ulaw [May 24 12:35:51] DEBUG[4309] bridging.c: Bridge 0xb7dbdb20 is happy that channel SIP/61-00000003 already has write format ulaw [May 24 12:35:51] DEBUG[4309] bridging.c: Giving bridge technology multiplexed_bridge notification that 0xb79b2998 is joining bridge 0xb7dbdb20 [May 24 12:35:51] DEBUG[4309] bridge_multiplexed.c: Adding channel 'SIP/61-00000003' to multiplexed thread '0xb7dbdb90' for monitoring [May 24 12:35:51] DEBUG[4309] bridging.c: Going into a single threaded signal wait for bridge channel 0xb79b2998 of bridge 0xb7dbdb20 [May 24 12:35:51] DEBUG[4310] bridge_multiplexed.c: Starting actual thread for multiplexed thread '0xb7dbdb90' [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: No remote address on RTP instance '0x9fa6338' so dropping frame [May 24 12:35:51] DEBUG[4300] chan_sip.c: = Looking for Call ID: 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 (Checking From) --From tag E74FF351-615ED192 --To-tag as0d862500 [May 24 12:35:51] DEBUG[4300] chan_sip.c: **** Received REFER (9) - Command in SIP REFER [May 24 12:35:51] DEBUG[4300] chan_sip.c: Attended transfer: Will use Replace-Call-ID : a8efdd04-fcc48d-1043aa6e@192.168.77.55 F-tag: 59F6CB50-DA67CBF9 T-tag: as1eb33679 [May 24 12:35:51] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 202' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:35:51] DEBUG[4300] chan_sip.c: Looking for callid a8efdd04-fcc48d-1043aa6e@192.168.77.55 (fromtag 59F6CB50-DA67CBF9 totag as1eb33679) [May 24 12:35:51] DEBUG[4300] chan_sip.c: Matched INCOMING call - their tag is 59F6CB50-DA67CBF9 Our tag is as1eb33679 [May 24 12:35:51] DEBUG[4300] chan_sip.c: SIP attended transfer: Error: No target channel [May 24 12:35:51] DEBUG[4300] chan_sip.c: Sip transfer:-------------------- [May 24 12:35:51] DEBUG[4300] chan_sip.c: -- Transferer to PBX channel: SIP/61-00000000 State Up [May 24 12:35:51] DEBUG[4300] chan_sip.c: -- Transferer to PBX second channel (target): SIP/61-00000003 State Up [May 24 12:35:51] DEBUG[4300] chan_sip.c: -- Bridged call to transferee: DAHDI/2-1 State Up [May 24 12:35:51] DEBUG[4300] chan_sip.c: -- No target second channel --- [May 24 12:35:51] DEBUG[4300] chan_sip.c: -- END Sip transfer:-------------------- [May 24 12:35:51] DEBUG[4300] chan_sip.c: SIP transfer: Four channels to handle [May 24 12:35:51] DEBUG[4300] chan_sip.c: SIP transfer: trying to masquerade DAHDI/2-1 into SIP/61-00000003 [May 24 12:35:51] DEBUG[4300] channel.c: Planning to masquerade channel DAHDI/2-1 into the structure of SIP/61-00000003 [May 24 12:35:51] DEBUG[4300] channel.c: Done planning to masquerade channel DAHDI/2-1 into the structure of SIP/61-00000003 [May 24 12:35:51] DEBUG[4300] chan_sip.c: SIP transfer: Succeeded to masquerade channels. [May 24 12:35:51] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:35:51] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:35:51] DEBUG[4300] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:35:51] DEBUG[4310] channel.c: Actually Masquerading DAHDI/2-1(6) into the structure of SIP/61-00000003(6) [May 24 12:35:51] DEBUG[4310] chan_sip.c: SIP Fixup: New owner for dialogue a8efdd04-fcc48d-1043aa6e@192.168.77.55: DAHDI/2-1 (Old parent: DAHDI/2-1) [May 24 12:35:51] DEBUG[4310] chan_sip.c: Hangup call DAHDI/2-1, SIP callid a8efdd04-fcc48d-1043aa6e@192.168.77.55 [May 24 12:35:51] DEBUG[4310] chan_sip.c: Updating call counter for incoming call [May 24 12:35:51] DEBUG[4310] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fbb1d8' [May 24 12:35:51] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:35:51] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:35:51] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:35:51] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:35:51] DEBUG[4310] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:35:51] DEBUG[4310] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:35:51] DEBUG[4310] chan_sip.c: Trying to put 'BYE sip:61@' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:35:51] DEBUG[4310] channel.c: Putting channel DAHDI/2-1 in ulaw/ulaw formats [May 24 12:35:51] DEBUG[4310] chan_dahdi.c: New owner for channel 2 is DAHDI/2-1 [May 24 12:35:51] DEBUG[4310] chan_dahdi.c: Updated conferencing on 2, with 0 conference users [May 24 12:35:51] DEBUG[4310] sig_analog.c: New owner for channel 2 is DAHDI/2-1 [May 24 12:35:51] DEBUG[4310] sig_analog.c: Updated conferencing on 2, with 0 conference users [May 24 12:35:51] DEBUG[4310] chan_dahdi.c: Updated conferencing on 2, with 0 conference users [May 24 12:35:51] DEBUG[4310] channel.c: Released clone lock on 'SIP/61-00000003' [May 24 12:35:51] DEBUG[4310] channel.c: Done Masquerading DAHDI/2-1 (6) [May 24 12:35:51] DEBUG[4310] chan_dahdi.c: Requested indication 26 on channel DAHDI/2-1 [May 24 12:35:51] DEBUG[4308] channel.c: Bridge stops because we're zombie or need a soft hangup: c0=SIP/61-00000003, c1=SIP/61-00000000, flags: Yes,Yes,No,No [May 24 12:35:51] DEBUG[4308] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 24 12:35:51] DEBUG[4308] channel.c: Bridge stops bridging channels SIP/61-00000003 and SIP/61-00000000 [May 24 12:35:51] DEBUG[4300] chan_dahdi.c: Requested indication 17 on channel DAHDI/2-1 [May 24 12:35:51] DEBUG[4308] channel.c: Hanging up channel 'SIP/61-00000000' [May 24 12:35:51] DEBUG[4310] chan_dahdi.c: Requested indication 22 on channel DAHDI/2-1 [May 24 12:35:51] DEBUG[4308] chan_sip.c: Updating call counter for outgoing call [May 24 12:35:51] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:35:51] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:35:51] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 1 (Not in use) [May 24 12:35:51] DEBUG[4293] devicestate.c: device 'SIP/61' state '1' [May 24 12:35:51] DEBUG[4308] chan_sip.c: SIP Transfer: Not hanging up right now... Rescheduling hangup for 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060. [May 24 12:35:51] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:35:51] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:35:51] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 1 (Not in use) [May 24 12:35:51] DEBUG[4293] devicestate.c: device 'SIP/61' state '1' [May 24 12:35:51] DEBUG[4308] app_dial.c: Exiting with DIALSTATUS=ANSWER. [May 24 12:35:51] DEBUG[4308] pbx.c: Spawn extension (external,s,3) exited non-zero on 'SIP/61-00000003' [May 24 12:35:51] VERBOSE[4308] pbx.c: == Spawn extension (external, s, 3) exited non-zero on 'SIP/61-00000003' [May 24 12:35:51] DEBUG[4308] channel.c: Soft-Hanging up channel 'SIP/61-00000003' [May 24 12:35:51] DEBUG[4308] channel.c: Hanging up zombie 'SIP/61-00000003' [May 24 12:35:51] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:35:51] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:35:51] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 1 (Not in use) [May 24 12:35:51] DEBUG[4293] devicestate.c: device 'SIP/61' state '1' [May 24 12:35:51] DEBUG[4300] chan_sip.c: = Looking for Call ID: 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 (Checking To) --From tag as0d862500 --To-tag E74FF351-615ED192 [May 24 12:35:51] DEBUG[4300] chan_sip.c: Stopping retransmission on '59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060' of Request 103: Match Found [May 24 12:35:51] DEBUG[4300] chan_sip.c: = Looking for Call ID: a8efdd04-fcc48d-1043aa6e@192.168.77.55 (Checking To) --From tag as1eb33679 --To-tag 59F6CB50-DA67CBF9 [May 24 12:35:51] DEBUG[4300] chan_sip.c: Stopping retransmission on 'a8efdd04-fcc48d-1043aa6e@192.168.77.55' of Request 102: Match Found [May 24 12:35:51] DEBUG[4300] chan_sip.c: Destroying SIP dialog a8efdd04-fcc48d-1043aa6e@192.168.77.55 [May 24 12:35:51] DEBUG[4300] rtp_engine.c: Destroyed RTP instance '0x9fbb1d8' [May 24 12:35:51] DEBUG[4300] chan_sip.c: = Looking for Call ID: 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 (Checking From) --From tag E74FF351-615ED192 --To-tag as0d862500 [May 24 12:35:51] DEBUG[4300] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [May 24 12:35:51] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:35:51] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:35:51] DEBUG[4300] chan_sip.c: Setting SIP_ALREADYGONE on dialog 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 [May 24 12:35:51] DEBUG[4300] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fa6338' [May 24 12:35:51] DEBUG[4300] chan_sip.c: Received bye, no owner, selfdestruct soon. [May 24 12:35:51] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:35:58] DEBUG[4301] chan_dahdi.c: Monitor doohicky got event Ring Begin on channel 3 [May 24 12:35:58] DEBUG[4301] sig_analog.c: channel (3) - signaling (5) - event (ANALOG_EVENT_RINGBEGIN) [May 24 12:35:59] DEBUG[4301] chan_dahdi.c: Monitor doohicky got event Ring/Answered on channel 3 [May 24 12:35:59] DEBUG[4301] sig_analog.c: channel (3) - signaling (5) - event (ANALOG_EVENT_RINGOFFHOOK) [May 24 12:35:59] DEBUG[4301] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [May 24 12:35:59] DEBUG[4301] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [May 24 12:35:59] DEBUG[4301] devicestate.c: device 'DAHDI/3-1' state '2' [May 24 12:35:59] DEBUG[4311] sig_analog.c: __analog_ss_thread 3 [May 24 12:35:59] VERBOSE[4311] sig_analog.c: -- Starting simple switch on 'DAHDI/3-1' [May 24 12:36:00] DEBUG[4311] chan_dahdi.c: CallerID number: 2067693770, name: BRANDLI BJ , flags=0 [May 24 12:36:00] DEBUG[4311] pbx.c: Launching 'Answer' [May 24 12:36:00] VERBOSE[4311] pbx.c: -- Executing [s@external:1] Answer("DAHDI/3-1", "") in new stack [May 24 12:36:00] DEBUG[4311] sig_analog.c: analog_answer 3 [May 24 12:36:00] DEBUG[4311] sig_analog.c: Took DAHDI/3-1 off hook [May 24 12:36:00] DEBUG[4311] chan_dahdi.c: Enabled echo cancellation on channel 3 [May 24 12:36:00] DEBUG[4311] chan_dahdi.c: No echo training requested [May 24 12:36:00] DEBUG[4311] chan_dahdi.c: Requested indication -1 on channel DAHDI/3-1 [May 24 12:36:00] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for DAHDI - 3 [May 24 12:36:00] DEBUG[4293] devicestate.c: Changing state for DAHDI/3 - state 2 (In use) [May 24 12:36:00] DEBUG[4293] devicestate.c: device 'DAHDI/3' state '2' [May 24 12:36:00] DEBUG[4311] pbx.c: Function result is '0' [May 24 12:36:00] DEBUG[4311] pbx.c: Expression result is '0' [May 24 12:36:00] DEBUG[4311] pbx.c: Launching 'GotoIf' [May 24 12:36:00] VERBOSE[4311] pbx.c: -- Executing [s@external:2] GotoIf("DAHDI/3-1", "0?closed,s,1") in new stack [May 24 12:36:00] DEBUG[4311] pbx.c: Not taking any branch [May 24 12:36:00] DEBUG[4311] pbx.c: Launching 'Dial' [May 24 12:36:00] VERBOSE[4311] pbx.c: -- Executing [s@external:3] Dial("DAHDI/3-1", "SIP/61&SIP/63&SIP/65,15,t") in new stack [May 24 12:36:00] DEBUG[4311] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: Allocating new SIP dialog for 1aee26e77d3ee4c92099ebf82e54004a@192.168.136.15:0 - INVITE (No RTP) [May 24 12:36:00] DEBUG[4311] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9fbb168' [May 24 12:36:00] DEBUG[4311] res_rtp_asterisk.c: Allocated port 17644 for RTP instance '0x9fbb168' [May 24 12:36:00] DEBUG[4311] rtp_engine.c: RTP instance '0x9fbb168' is setup and ready to go [May 24 12:36:00] DEBUG[4311] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9fbb168' [May 24 12:36:00] VERBOSE[4311] netsock2.c: == Using SIP RTP CoS mark 5 [May 24 12:36:00] DEBUG[4311] chan_sip.c: Setting NAT on RTP to Off [May 24 12:36:00] DEBUG[4311] acl.c: For destination '192.168.77.55', our source address is '192.168.77.20'. [May 24 12:36:00] DEBUG[4311] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.77.20:5060 [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Our native formats are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Our capabilities are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: This channel will not be able to handle video. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALEDTIME. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable ANSWEREDTIME. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALEDPEERNAME. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALEDPEERNUMBER. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALSTATUS. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DB_RESULT. [May 24 12:36:00] DEBUG[4311] chan_sip.c: Outgoing Call for 61 [May 24 12:36:00] DEBUG[4311] chan_sip.c: Updating call counter for outgoing call [May 24 12:36:00] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:00] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:00] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 6 (Ringing) [May 24 12:36:00] DEBUG[4293] devicestate.c: device 'SIP/61' state '6' [May 24 12:36:00] DEBUG[4311] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: False Text flag: False [May 24 12:36:00] DEBUG[4311] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: -- Done with adding codecs to SDP [May 24 12:36:00] DEBUG[4311] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: Initializing initreq for method INVITE - callid 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 [May 24 12:36:00] DEBUG[4311] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:36:00] VERBOSE[4311] app_dial.c: -- Called 61 [May 24 12:36:00] DEBUG[4311] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: Allocating new SIP dialog for 757e21e6753b07b4239086875dfe1979@192.168.136.15:0 - INVITE (No RTP) [May 24 12:36:00] DEBUG[4311] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb7db99d8' [May 24 12:36:00] DEBUG[4311] res_rtp_asterisk.c: Allocated port 25168 for RTP instance '0xb7db99d8' [May 24 12:36:00] DEBUG[4311] rtp_engine.c: RTP instance '0xb7db99d8' is setup and ready to go [May 24 12:36:00] DEBUG[4311] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb7db99d8' [May 24 12:36:00] VERBOSE[4311] netsock2.c: == Using SIP RTP CoS mark 5 [May 24 12:36:00] DEBUG[4311] chan_sip.c: Setting NAT on RTP to Off [May 24 12:36:00] DEBUG[4311] acl.c: For destination '192.168.77.53', our source address is '192.168.77.20'. [May 24 12:36:00] DEBUG[4311] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.77.20:5060 [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Our native formats are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Our capabilities are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: This channel will not be able to handle video. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALEDTIME. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable ANSWEREDTIME. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALEDPEERNAME. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALEDPEERNUMBER. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALSTATUS. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DB_RESULT. [May 24 12:36:00] DEBUG[4311] chan_sip.c: Outgoing Call for 63 [May 24 12:36:00] DEBUG[4311] chan_sip.c: Updating call counter for outgoing call [May 24 12:36:00] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 63 [May 24 12:36:00] DEBUG[4293] chan_sip.c: Checking device state for peer 63 [May 24 12:36:00] DEBUG[4293] devicestate.c: Changing state for SIP/63 - state 6 (Ringing) [May 24 12:36:00] DEBUG[4293] devicestate.c: device 'SIP/63' state '6' [May 24 12:36:00] DEBUG[4311] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: False Text flag: False [May 24 12:36:00] DEBUG[4311] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: -- Done with adding codecs to SDP [May 24 12:36:00] DEBUG[4311] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: Initializing initreq for method INVITE - callid 038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060 [May 24 12:36:00] DEBUG[4311] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.77.53:5060 [May 24 12:36:00] VERBOSE[4311] app_dial.c: -- Called 63 [May 24 12:36:00] DEBUG[4311] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: Allocating new SIP dialog for 0ef6365321c852d0500f54ba18f01b9f@192.168.136.15:0 - INVITE (No RTP) [May 24 12:36:00] DEBUG[4311] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9fc6198' [May 24 12:36:00] DEBUG[4311] res_rtp_asterisk.c: Allocated port 24294 for RTP instance '0x9fc6198' [May 24 12:36:00] DEBUG[4311] rtp_engine.c: RTP instance '0x9fc6198' is setup and ready to go [May 24 12:36:00] DEBUG[4311] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9fc6198' [May 24 12:36:00] VERBOSE[4311] netsock2.c: == Using SIP RTP CoS mark 5 [May 24 12:36:00] DEBUG[4311] chan_sip.c: Setting NAT on RTP to Off [May 24 12:36:00] DEBUG[4311] acl.c: For destination '192.168.77.51', our source address is '192.168.77.20'. [May 24 12:36:00] DEBUG[4311] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.77.20:5060 [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Our native formats are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Our capabilities are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: This channel will not be able to handle video. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALEDTIME. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable ANSWEREDTIME. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALEDPEERNAME. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALEDPEERNUMBER. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DIALSTATUS. [May 24 12:36:00] DEBUG[4311] channel.c: Not copying variable DB_RESULT. [May 24 12:36:00] DEBUG[4311] chan_sip.c: Outgoing Call for 65 [May 24 12:36:00] DEBUG[4311] chan_sip.c: Updating call counter for outgoing call [May 24 12:36:00] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 65 [May 24 12:36:00] DEBUG[4293] chan_sip.c: Checking device state for peer 65 [May 24 12:36:00] DEBUG[4293] devicestate.c: Changing state for SIP/65 - state 6 (Ringing) [May 24 12:36:00] DEBUG[4293] devicestate.c: device 'SIP/65' state '6' [May 24 12:36:00] DEBUG[4311] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: False Text flag: False [May 24 12:36:00] DEBUG[4311] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: -- Done with adding codecs to SDP [May 24 12:36:00] DEBUG[4311] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [May 24 12:36:00] DEBUG[4311] chan_sip.c: Initializing initreq for method INVITE - callid 58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060 [May 24 12:36:00] DEBUG[4311] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.77.51:5060 [May 24 12:36:00] VERBOSE[4311] app_dial.c: -- Called 65 [May 24 12:36:00] DEBUG[4300] chan_sip.c: = Looking for Call ID: 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 (Checking To) --From tag as63939bc3 --To-tag 1C7DB0CA-E321C3E3 [May 24 12:36:00] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060' Request 102: Found [May 24 12:36:00] DEBUG[4300] chan_sip.c: SIP response 100 to standard invite [May 24 12:36:00] DEBUG[4300] chan_sip.c: = Looking for Call ID: 038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060 (Checking To) --From tag as1c666d56 --To-tag 29E382C1-C72075FC [May 24 12:36:00] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060' Request 102: Found [May 24 12:36:00] DEBUG[4300] chan_sip.c: SIP response 100 to standard invite [May 24 12:36:00] DEBUG[4300] chan_sip.c: = Looking for Call ID: 58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060 (Checking To) --From tag as0b5aaeca --To-tag 7AD0E0C2-572B7C17 [May 24 12:36:00] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060' Request 102: Found [May 24 12:36:00] DEBUG[4300] chan_sip.c: SIP response 100 to standard invite [May 24 12:36:00] DEBUG[4300] chan_sip.c: = Looking for Call ID: 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 (Checking To) --From tag as63939bc3 --To-tag 1C7DB0CA-E321C3E3 [May 24 12:36:00] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060' Request 102: Found [May 24 12:36:00] DEBUG[4300] chan_sip.c: SIP response 180 to standard invite [May 24 12:36:00] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:00] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:00] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 6 (Ringing) [May 24 12:36:00] DEBUG[4293] devicestate.c: device 'SIP/61' state '6' [May 24 12:36:00] VERBOSE[4311] app_dial.c: -- SIP/61-00000004 is ringing [May 24 12:36:00] DEBUG[4311] chan_dahdi.c: Requested indication 3 on channel DAHDI/3-1 [May 24 12:36:01] DEBUG[4300] chan_sip.c: = Looking for Call ID: 58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060 (Checking To) --From tag as0b5aaeca --To-tag 7AD0E0C2-572B7C17 [May 24 12:36:01] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060' Request 102: Found [May 24 12:36:01] DEBUG[4300] chan_sip.c: SIP response 180 to standard invite [May 24 12:36:01] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 65 [May 24 12:36:01] DEBUG[4293] chan_sip.c: Checking device state for peer 65 [May 24 12:36:01] DEBUG[4293] devicestate.c: Changing state for SIP/65 - state 6 (Ringing) [May 24 12:36:01] DEBUG[4293] devicestate.c: device 'SIP/65' state '6' [May 24 12:36:01] VERBOSE[4311] app_dial.c: -- SIP/65-00000006 is ringing [May 24 12:36:01] DEBUG[4300] chan_sip.c: = Looking for Call ID: 038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060 (Checking To) --From tag as1c666d56 --To-tag 29E382C1-C72075FC [May 24 12:36:01] DEBUG[4300] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060' Request 102: Found [May 24 12:36:01] DEBUG[4300] chan_sip.c: SIP response 180 to standard invite [May 24 12:36:01] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 63 [May 24 12:36:01] DEBUG[4293] chan_sip.c: Checking device state for peer 63 [May 24 12:36:01] DEBUG[4293] devicestate.c: Changing state for SIP/63 - state 6 (Ringing) [May 24 12:36:01] DEBUG[4293] devicestate.c: device 'SIP/63' state '6' [May 24 12:36:01] VERBOSE[4311] app_dial.c: -- SIP/63-00000005 is ringing [May 24 12:36:02] DEBUG[4300] chan_sip.c: = Looking for Call ID: 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 (Checking To) --From tag as63939bc3 --To-tag 1C7DB0CA-E321C3E3 [May 24 12:36:02] DEBUG[4300] chan_sip.c: Acked pending invite 102 [May 24 12:36:02] DEBUG[4300] chan_sip.c: Stopping retransmission on '0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060' of Request 102: Match Found [May 24 12:36:02] DEBUG[4300] chan_sip.c: SIP response 200 to standard invite [May 24 12:36:02] DEBUG[4300] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 24 12:36:02] DEBUG[4300] chan_sip.c: Processing session-level SDP o=- 1306265747 1306265747 IN IP4 192.168.77.55... UNSUPPORTED. [May 24 12:36:02] DEBUG[4300] chan_sip.c: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED. [May 24 12:36:02] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:36:02] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:36:02] DEBUG[4300] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.77.55... OK. [May 24 12:36:02] DEBUG[4300] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 24 12:36:02] DEBUG[4300] rtp_engine.c: Setting payload 0 based on m type on 0xb7b594fc [May 24 12:36:02] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [May 24 12:36:02] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 24 12:36:02] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:127 telephone-event/8000... OK. [May 24 12:36:02] DEBUG[4300] rtp_engine.c: Incorporating payload 0 on 0xb7b594fc [May 24 12:36:02] DEBUG[4300] rtp_engine.c: Incorporating payload 127 on 0xb7b594fc [May 24 12:36:02] DEBUG[4300] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fbb168' [May 24 12:36:02] DEBUG[4300] rtp_engine.c: Copying payload 0 from 0xb7b594fc to 0x9fbb314 [May 24 12:36:02] DEBUG[4300] rtp_engine.c: Copying payload 127 from 0xb7b594fc to 0x9fbb314 [May 24 12:36:02] DEBUG[4300] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [May 24 12:36:02] DEBUG[4300] chan_sip.c: We have an owner, now see if we need to change this call [May 24 12:36:02] DEBUG[4300] chan_sip.c: Updating call counter for outgoing call [May 24 12:36:02] DEBUG[4300] chan_sip.c: build_route: Contact hop: [May 24 12:36:02] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:02] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:02] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:36:02] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:36:02] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:36:02] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:36:02] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:36:02] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:36:02] DEBUG[4300] chan_sip.c: Trying to put 'ACK sip:61@' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:36:02] VERBOSE[4311] app_dial.c: -- SIP/61-00000004 connected line has changed. Saving it until answer for DAHDI/3-1 [May 24 12:36:02] VERBOSE[4311] app_dial.c: -- SIP/61-00000004 answered DAHDI/3-1 [May 24 12:36:02] DEBUG[4311] chan_dahdi.c: Requested indication 22 on channel DAHDI/3-1 [May 24 12:36:02] DEBUG[4311] channel.c: Hanging up channel 'SIP/65-00000006' [May 24 12:36:02] DEBUG[4311] chan_sip.c: This call was answered elsewhere[May 24 12:36:02] DEBUG[4311] chan_sip.c: ####### It's the cause code, buddy. The cause code!!! [May 24 12:36:02] DEBUG[4311] chan_sip.c: Hangup call SIP/65-00000006, SIP callid 58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060 [May 24 12:36:02] DEBUG[4311] chan_sip.c: Updating call counter for outgoing call [May 24 12:36:02] DEBUG[4311] chan_sip.c: Hanging up channel in state Ringing (not UP) [May 24 12:36:02] DEBUG[4311] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fc6198' [May 24 12:36:02] DEBUG[4311] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060' Request 102: Found [May 24 12:36:02] DEBUG[4311] chan_sip.c: Trying to put 'CANCEL sip:' onto UDP socket destined for 192.168.77.51:5060 [May 24 12:36:02] DEBUG[4311] channel.c: Hanging up channel 'SIP/63-00000005' [May 24 12:36:02] DEBUG[4311] chan_sip.c: This call was answered elsewhere[May 24 12:36:02] DEBUG[4311] chan_sip.c: ####### It's the cause code, buddy. The cause code!!! [May 24 12:36:02] DEBUG[4311] chan_sip.c: Hangup call SIP/63-00000005, SIP callid 038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060 [May 24 12:36:02] DEBUG[4311] chan_sip.c: Updating call counter for outgoing call [May 24 12:36:02] DEBUG[4311] chan_sip.c: Hanging up channel in state Ringing (not UP) [May 24 12:36:02] DEBUG[4311] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb7db99d8' [May 24 12:36:02] DEBUG[4311] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060' Request 102: Found [May 24 12:36:02] DEBUG[4311] chan_sip.c: Trying to put 'CANCEL sip:' onto UDP socket destined for 192.168.77.53:5060 [May 24 12:36:02] DEBUG[4311] features.c: bridge answer set, chan answer set [May 24 12:36:02] DEBUG[4311] chan_dahdi.c: Requested indication 20 on channel DAHDI/3-1 [May 24 12:36:02] DEBUG[4311] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 24 12:36:02] DEBUG[4311] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [May 24 12:36:02] DEBUG[4311] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [May 24 12:36:02] DEBUG[4311] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x9fbb168' [May 24 12:36:02] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:02] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:02] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:36:02] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:36:02] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 65 [May 24 12:36:02] DEBUG[4293] chan_sip.c: Checking device state for peer 65 [May 24 12:36:02] DEBUG[4293] devicestate.c: Changing state for SIP/65 - state 1 (Not in use) [May 24 12:36:02] DEBUG[4293] devicestate.c: device 'SIP/65' state '1' [May 24 12:36:02] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 65 [May 24 12:36:02] DEBUG[4293] chan_sip.c: Checking device state for peer 65 [May 24 12:36:02] DEBUG[4293] devicestate.c: Changing state for SIP/65 - state 1 (Not in use) [May 24 12:36:02] DEBUG[4293] devicestate.c: device 'SIP/65' state '1' [May 24 12:36:02] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 63 [May 24 12:36:02] DEBUG[4293] chan_sip.c: Checking device state for peer 63 [May 24 12:36:02] DEBUG[4293] devicestate.c: Changing state for SIP/63 - state 1 (Not in use) [May 24 12:36:02] DEBUG[4293] devicestate.c: device 'SIP/63' state '1' [May 24 12:36:02] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 63 [May 24 12:36:02] DEBUG[4293] chan_sip.c: Checking device state for peer 63 [May 24 12:36:02] DEBUG[4293] devicestate.c: Changing state for SIP/63 - state 1 (Not in use) [May 24 12:36:02] DEBUG[4293] devicestate.c: device 'SIP/63' state '1' [May 24 12:36:02] DEBUG[4300] chan_sip.c: = Looking for Call ID: 58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060 (Checking To) --From tag as0b5aaeca --To-tag [May 24 12:36:02] DEBUG[4300] chan_sip.c: Acked pending invite 102 [May 24 12:36:02] DEBUG[4300] chan_sip.c: Stopping retransmission on '58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060' of Request 102: Match Found [May 24 12:36:02] DEBUG[4300] chan_sip.c: = Looking for Call ID: 038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060 (Checking To) --From tag as1c666d56 --To-tag [May 24 12:36:02] DEBUG[4300] chan_sip.c: Acked pending invite 102 [May 24 12:36:02] DEBUG[4300] chan_sip.c: Stopping retransmission on '038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060' of Request 102: Match Found [May 24 12:36:02] DEBUG[4300] chan_sip.c: = Looking for Call ID: 58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060 (Checking To) --From tag as0b5aaeca --To-tag 7AD0E0C2-572B7C17 [May 24 12:36:02] DEBUG[4300] chan_sip.c: Stopping retransmission on '58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060' of Request 102: Match Found [May 24 12:36:02] DEBUG[4300] chan_sip.c: SIP response 487 to standard invite [May 24 12:36:02] DEBUG[4300] chan_sip.c: Trying to put 'ACK sip:65@' onto UDP socket destined for 192.168.77.51:5060 [May 24 12:36:02] DEBUG[4300] chan_sip.c: Updating call counter for outgoing call [May 24 12:36:02] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 65 [May 24 12:36:02] DEBUG[4293] chan_sip.c: Checking device state for peer 65 [May 24 12:36:02] DEBUG[4293] devicestate.c: Changing state for SIP/65 - state 1 (Not in use) [May 24 12:36:02] DEBUG[4293] devicestate.c: device 'SIP/65' state '1' [May 24 12:36:02] DEBUG[4300] chan_sip.c: Setting SIP_ALREADYGONE on dialog 58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060 [May 24 12:36:02] DEBUG[4300] chan_sip.c: Destroying SIP dialog 58a44ad471f3bda222602a0f62900cac@192.168.77.20:5060 [May 24 12:36:02] DEBUG[4300] rtp_engine.c: Destroyed RTP instance '0x9fc6198' [May 24 12:36:02] DEBUG[4300] chan_sip.c: = Looking for Call ID: 038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060 (Checking To) --From tag as1c666d56 --To-tag 29E382C1-C72075FC [May 24 12:36:02] DEBUG[4300] chan_sip.c: Stopping retransmission on '038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060' of Request 102: Match Found [May 24 12:36:02] DEBUG[4300] chan_sip.c: SIP response 487 to standard invite [May 24 12:36:02] DEBUG[4300] chan_sip.c: Trying to put 'ACK sip:63@' onto UDP socket destined for 192.168.77.53:5060 [May 24 12:36:02] DEBUG[4300] chan_sip.c: Updating call counter for outgoing call [May 24 12:36:02] DEBUG[4300] chan_sip.c: Setting SIP_ALREADYGONE on dialog 038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060 [May 24 12:36:02] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 63 [May 24 12:36:02] DEBUG[4300] chan_sip.c: Destroying SIP dialog 038710b84438abd3476b43fc6b2e24d0@192.168.77.20:5060 [May 24 12:36:02] DEBUG[4300] rtp_engine.c: Destroyed RTP instance '0xb7db99d8' [May 24 12:36:02] DEBUG[4293] chan_sip.c: Checking device state for peer 63 [May 24 12:36:02] DEBUG[4293] devicestate.c: Changing state for SIP/63 - state 1 (Not in use) [May 24 12:36:02] DEBUG[4293] devicestate.c: device 'SIP/63' state '1' [May 24 12:36:03] DEBUG[4300] chan_sip.c: = Looking for Call ID: 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 (Checking From) --From tag 1C7DB0CA-E321C3E3 --To-tag as63939bc3 [May 24 12:36:03] DEBUG[4300] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 24 12:36:03] DEBUG[4300] sip/reqresp_parser.c: Begin: parsing SIP "Supported: 100rel,replaces" [May 24 12:36:03] DEBUG[4300] sip/reqresp_parser.c: Found SIP option: -100rel- [May 24 12:36:03] DEBUG[4300] sip/reqresp_parser.c: Matched SIP option: 100rel [May 24 12:36:03] DEBUG[4300] sip/reqresp_parser.c: Found SIP option: -replaces- [May 24 12:36:03] DEBUG[4300] sip/reqresp_parser.c: Matched SIP option: replaces [May 24 12:36:03] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:36:03] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:36:03] DEBUG[4300] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 24 12:36:03] DEBUG[4300] chan_sip.c: Processing session-level SDP o=- 1306265747 1306265748 IN IP4 192.168.77.55... UNSUPPORTED. [May 24 12:36:03] DEBUG[4300] chan_sip.c: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED. [May 24 12:36:03] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:36:03] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:36:03] DEBUG[4300] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.77.55... OK. [May 24 12:36:03] DEBUG[4300] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 24 12:36:03] DEBUG[4300] chan_sip.c: Processing session-level SDP a=sendonly... OK. [May 24 12:36:03] DEBUG[4300] rtp_engine.c: Setting payload 0 based on m type on 0xb7b5939c [May 24 12:36:03] DEBUG[4300] rtp_engine.c: Setting payload 101 based on m type on 0xb7b5939c [May 24 12:36:03] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=sendonly... OK. [May 24 12:36:03] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 24 12:36:03] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 24 12:36:03] DEBUG[4300] rtp_engine.c: Incorporating payload 0 on 0xb7b5939c [May 24 12:36:03] DEBUG[4300] rtp_engine.c: Incorporating payload 101 on 0xb7b5939c [May 24 12:36:03] DEBUG[4300] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fbb168' [May 24 12:36:03] DEBUG[4300] rtp_engine.c: Copying payload 0 from 0xb7b5939c to 0x9fbb314 [May 24 12:36:03] DEBUG[4300] rtp_engine.c: Copying payload 101 from 0xb7b5939c to 0x9fbb314 [May 24 12:36:03] DEBUG[4300] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [May 24 12:36:03] DEBUG[4300] chan_sip.c: We have an owner, now see if we need to change this call [May 24 12:36:03] DEBUG[4300] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fbb168' [May 24 12:36:03] DEBUG[4300] chan_sip.c: SIP/61-00000004: This call is UP.... [May 24 12:36:03] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:36:03] DEBUG[4300] chan_sip.c: Setting framing from config on incoming call [May 24 12:36:03] DEBUG[4300] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True Text flag: True [May 24 12:36:03] DEBUG[4300] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [May 24 12:36:03] DEBUG[4300] chan_sip.c: -- Done with adding codecs to SDP [May 24 12:36:03] DEBUG[4300] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [May 24 12:36:03] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:36:03] DEBUG[4311] chan_dahdi.c: Requested indication 16 on channel DAHDI/3-1 [May 24 12:36:03] VERBOSE[4311] channel.c: -- Music class default requested but no musiconhold loaded. [May 24 12:36:03] DEBUG[4311] chan_dahdi.c: Requested indication 20 on channel DAHDI/3-1 [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4300] chan_sip.c: = Looking for Call ID: 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 (Checking From) --From tag 1C7DB0CA-E321C3E3 --To-tag as63939bc3 [May 24 12:36:03] DEBUG[4300] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 24 12:36:03] DEBUG[4300] chan_sip.c: Stopping retransmission on '0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060' of Response 1: Match Found [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:03] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4300] chan_sip.c: = Looking for Call ID: 51b6f385-47abd4a6-d26d1e5f@192.168.77.55 (Checking From) --From tag 852099F1-F1B28732 --To-tag [May 24 12:36:04] DEBUG[4300] acl.c: For destination '192.168.77.55', our source address is '192.168.77.20'. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.77.20:5060 [May 24 12:36:04] DEBUG[4300] chan_sip.c: Allocating new SIP dialog for 51b6f385-47abd4a6-d26d1e5f@192.168.77.55 - INVITE (No RTP) [May 24 12:36:04] DEBUG[4300] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 24 12:36:04] DEBUG[4300] sip/reqresp_parser.c: Begin: parsing SIP "Supported: 100rel,replaces" [May 24 12:36:04] DEBUG[4300] sip/reqresp_parser.c: Found SIP option: -100rel- [May 24 12:36:04] DEBUG[4300] sip/reqresp_parser.c: Matched SIP option: 100rel [May 24 12:36:04] DEBUG[4300] sip/reqresp_parser.c: Found SIP option: -replaces- [May 24 12:36:04] DEBUG[4300] sip/reqresp_parser.c: Matched SIP option: replaces [May 24 12:36:04] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:36:04] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:36:04] DEBUG[4300] chan_sip.c: = Looking for Call ID: 51b6f385-47abd4a6-d26d1e5f@192.168.77.55 (Checking From) --From tag 852099F1-F1B28732 --To-tag as48b5fb27 [May 24 12:36:04] DEBUG[4300] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 24 12:36:04] DEBUG[4300] chan_sip.c: Stopping retransmission on '51b6f385-47abd4a6-d26d1e5f@192.168.77.55' of Response 1: Match Found [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4300] chan_sip.c: = Looking for Call ID: 51b6f385-47abd4a6-d26d1e5f@192.168.77.55 (Checking From) --From tag 852099F1-F1B28732 --To-tag [May 24 12:36:04] DEBUG[4300] netsock2.c: Splitting '192.168.77.20' gives... [May 24 12:36:04] DEBUG[4300] netsock2.c: ...host '192.168.77.20' and port '(null)'. [May 24 12:36:04] DEBUG[4300] netsock2.c: Splitting '192.168.77.20' gives... [May 24 12:36:04] DEBUG[4300] netsock2.c: ...host '192.168.77.20' and port '(null)'. [May 24 12:36:04] DEBUG[4300] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 24 12:36:04] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:36:04] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9fc6618' [May 24 12:36:04] DEBUG[4300] res_rtp_asterisk.c: Allocated port 29570 for RTP instance '0x9fc6618' [May 24 12:36:04] DEBUG[4300] rtp_engine.c: RTP instance '0x9fc6618' is setup and ready to go [May 24 12:36:04] DEBUG[4300] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9fc6618' [May 24 12:36:04] VERBOSE[4300] netsock2.c: == Using SIP RTP CoS mark 5 [May 24 12:36:04] DEBUG[4300] chan_sip.c: Setting NAT on RTP to Off [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing session-level SDP o=- 1306265749 1306265749 IN IP4 192.168.77.55... UNSUPPORTED. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED. [May 24 12:36:04] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:36:04] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.77.55... OK. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing session-level SDP a=sendrecv... OK. [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Setting payload 9 based on m type on 0xb7b5939c [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Setting payload 0 based on m type on 0xb7b5939c [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Setting payload 8 based on m type on 0xb7b5939c [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Setting payload 18 based on m type on 0xb7b5939c [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED. [May 24 12:36:04] DEBUG[4300] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:127 telephone-event/8000... OK. [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Incorporating payload 0 on 0xb7b5939c [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Incorporating payload 8 on 0xb7b5939c [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Incorporating payload 9 on 0xb7b5939c [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Incorporating payload 18 on 0xb7b5939c [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Incorporating payload 127 on 0xb7b5939c [May 24 12:36:04] DEBUG[4300] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fc6618' [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Copying payload 0 from 0xb7b5939c to 0x9fc67c4 [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Copying payload 8 from 0xb7b5939c to 0x9fc67c4 [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Copying payload 9 from 0xb7b5939c to 0x9fc67c4 [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Copying payload 18 from 0xb7b5939c to 0x9fc67c4 [May 24 12:36:04] DEBUG[4300] rtp_engine.c: Copying payload 127 from 0xb7b5939c to 0x9fc67c4 [May 24 12:36:04] DEBUG[4300] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [May 24 12:36:04] DEBUG[4300] chan_sip.c: Checking SIP call limits for device 61 [May 24 12:36:04] DEBUG[4300] chan_sip.c: Updating call counter for incoming call [May 24 12:36:04] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:04] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:04] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:36:04] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:36:04] DEBUG[4300] chan_sip.c: *** Our native formats are 0x4 (ulaw) [May 24 12:36:04] DEBUG[4300] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [May 24 12:36:04] DEBUG[4300] chan_sip.c: *** Our capabilities are 0x4 (ulaw) [May 24 12:36:04] DEBUG[4300] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [May 24 12:36:04] DEBUG[4300] chan_sip.c: This channel will not be able to handle video. [May 24 12:36:04] DEBUG[4300] chan_sip.c: build_route: Contact hop: [May 24 12:36:04] DEBUG[4300] chan_sip.c: SIP/61-00000007: New call is still down.... Trying... [May 24 12:36:04] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:36:04] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:04] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:04] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:36:04] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:36:04] DEBUG[4312] pbx.c: Launching 'Set' [May 24 12:36:04] VERBOSE[4312] pbx.c: -- Executing [26@internal:1] Set("SIP/61-00000007", "CONFBRIDGE_JOIN_SOUND=en/beep") in new stack [May 24 12:36:04] DEBUG[4312] pbx.c: Launching 'Set' [May 24 12:36:04] VERBOSE[4312] pbx.c: -- Executing [26@internal:2] Set("SIP/61-00000007", "CONFBRIDGE_LEAVE_SOUND=en/beep") in new stack [May 24 12:36:04] DEBUG[4312] pbx.c: Launching 'Answer' [May 24 12:36:04] VERBOSE[4312] pbx.c: -- Executing [26@internal:3] Answer("SIP/61-00000007", "") in new stack [May 24 12:36:04] DEBUG[4312] chan_sip.c: SIP answering channel: SIP/61-00000007 [May 24 12:36:04] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:04] DEBUG[4312] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 24 12:36:04] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:04] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:36:04] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:36:04] DEBUG[4312] chan_sip.c: Setting framing from config on incoming call [May 24 12:36:04] DEBUG[4312] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True Text flag: True [May 24 12:36:04] DEBUG[4312] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [May 24 12:36:04] DEBUG[4312] chan_sip.c: -- Done with adding codecs to SDP [May 24 12:36:04] DEBUG[4312] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [May 24 12:36:04] DEBUG[4312] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4300] chan_sip.c: = Looking for Call ID: 51b6f385-47abd4a6-d26d1e5f@192.168.77.55 (Checking From) --From tag 852099F1-F1B28732 --To-tag as3212d3fc [May 24 12:36:04] DEBUG[4300] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 24 12:36:04] DEBUG[4300] chan_sip.c: Stopping retransmission on '51b6f385-47abd4a6-d26d1e5f@192.168.77.55' of Response 2: Match Found [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4312] pbx.c: Launching 'ConfBridge' [May 24 12:36:04] VERBOSE[4312] pbx.c: -- Executing [26@internal:4] ConfBridge("SIP/61-00000007", "26,1s") in new stack [May 24 12:36:04] DEBUG[4312] app_confbridge.c: Trying to find conference bridge '26' [May 24 12:36:04] DEBUG[4312] app_confbridge.c: Created a playback channel to conference bridge '26' [May 24 12:36:04] DEBUG[4312] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [May 24 12:36:04] VERBOSE[4312] file.c: -- Playing 'en/beep.slin' (language 'en') [May 24 12:36:04] DEBUG[4314] bridging.c: Joining bridge channel 0xb7db70c8 to bridge 0xb7dbdb20 [May 24 12:36:04] DEBUG[4314] bridging.c: Added channel Bridge/0xb7dbd8e8-output(0xb7db9e78) to bridge array on 0xb7dbdb20, new count is 2 [May 24 12:36:04] DEBUG[4314] bridging.c: Bridge 0xb7dbdb20 channel count (2) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [May 24 12:36:04] DEBUG[4314] bridging.c: Bridge 0xb7dbdb20 is happy that channel Bridge/0xb7dbd8e8-output already has read format slin [May 24 12:36:04] DEBUG[4314] bridging.c: Bridge 0xb7dbdb20 is happy that channel Bridge/0xb7dbd8e8-output already has write format slin [May 24 12:36:04] DEBUG[4314] bridging.c: Giving bridge technology multiplexed_bridge notification that 0xb7db70c8 is joining bridge 0xb7dbdb20 [May 24 12:36:04] DEBUG[4314] bridge_multiplexed.c: Adding channel 'Bridge/0xb7dbd8e8-output' to multiplexed thread '0xb7dbdb90' for monitoring [May 24 12:36:04] DEBUG[4314] channel.c: Set channel DAHDI/2-1 to read format slin [May 24 12:36:04] DEBUG[4314] channel.c: Set channel DAHDI/2-1 to write format slin [May 24 12:36:04] DEBUG[4314] bridging.c: Going into a single threaded signal wait for bridge channel 0xb7db70c8 of bridge 0xb7dbdb20 [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4312] channel.c: Scheduling timer at (364 requested / 364 actual) timer ticks per second [May 24 12:36:04] DEBUG[4312] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 24 12:36:04] DEBUG[4312] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 24 12:36:04] DEBUG[4312] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 24 12:36:04] DEBUG[4312] app_confbridge.c: Departing underlying channel 'Bridge/0xb7dbd8e8-output' from bridge '0xb7dbdb20' [May 24 12:36:04] DEBUG[4314] bridging.c: Giving bridge technology multiplexed_bridge notification that 0xb7db70c8 is leaving bridge 0xb7dbdb20 [May 24 12:36:04] DEBUG[4314] bridge_multiplexed.c: Removing channel 'Bridge/0xb7dbd8e8-output' from multiplexed thread '0xb7dbdb90' [May 24 12:36:04] DEBUG[4314] bridging.c: Removed channel 0xb7db9e78 from bridge array on 0xb7dbdb20, new count is 1 [May 24 12:36:04] DEBUG[4314] bridging.c: Bridge 0xb7dbdb20 channel count (1) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [May 24 12:36:04] DEBUG[4312] bridging.c: Joining bridge channel 0xb793a998 to bridge 0xb7dbdb20 [May 24 12:36:04] DEBUG[4312] bridging.c: Added channel SIP/61-00000007(0xb7dbcf98) to bridge array on 0xb7dbdb20, new count is 2 [May 24 12:36:04] DEBUG[4312] bridging.c: Bridge 0xb7dbdb20 channel count (2) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [May 24 12:36:04] DEBUG[4312] bridging.c: Bridge 0xb7dbdb20 is happy that channel SIP/61-00000007 already has read format ulaw [May 24 12:36:04] DEBUG[4312] bridging.c: Bridge 0xb7dbdb20 is happy that channel SIP/61-00000007 already has write format ulaw [May 24 12:36:04] DEBUG[4312] bridging.c: Giving bridge technology multiplexed_bridge notification that 0xb793a998 is joining bridge 0xb7dbdb20 [May 24 12:36:04] DEBUG[4312] bridge_multiplexed.c: Adding channel 'SIP/61-00000007' to multiplexed thread '0xb7dbdb90' for monitoring [May 24 12:36:04] DEBUG[4312] channel.c: Set channel DAHDI/2-1 to read format ulaw [May 24 12:36:04] DEBUG[4312] channel.c: Set channel DAHDI/2-1 to write format ulaw [May 24 12:36:04] DEBUG[4312] bridging.c: Going into a single threaded signal wait for bridge channel 0xb793a998 of bridge 0xb7dbdb20 [May 24 12:36:04] DEBUG[4310] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [May 24 12:36:04] DEBUG[4310] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:04] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: No remote address on RTP instance '0x9fbb168' so dropping frame [May 24 12:36:05] DEBUG[4300] chan_sip.c: = Looking for Call ID: 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 (Checking From) --From tag 1C7DB0CA-E321C3E3 --To-tag as63939bc3 [May 24 12:36:05] DEBUG[4300] chan_sip.c: **** Received REFER (9) - Command in SIP REFER [May 24 12:36:05] DEBUG[4300] chan_sip.c: Attended transfer: Will use Replace-Call-ID : 51b6f385-47abd4a6-d26d1e5f@192.168.77.55 F-tag: 852099F1-F1B28732 T-tag: as3212d3fc [May 24 12:36:05] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 202' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:36:05] DEBUG[4300] chan_sip.c: Looking for callid 51b6f385-47abd4a6-d26d1e5f@192.168.77.55 (fromtag 852099F1-F1B28732 totag as3212d3fc) [May 24 12:36:05] DEBUG[4300] chan_sip.c: Matched INCOMING call - their tag is 852099F1-F1B28732 Our tag is as3212d3fc [May 24 12:36:05] DEBUG[4300] chan_sip.c: SIP attended transfer: Error: No target channel [May 24 12:36:05] DEBUG[4300] chan_sip.c: Sip transfer:-------------------- [May 24 12:36:05] DEBUG[4300] chan_sip.c: -- Transferer to PBX channel: SIP/61-00000004 State Up [May 24 12:36:05] DEBUG[4300] chan_sip.c: -- Transferer to PBX second channel (target): SIP/61-00000007 State Up [May 24 12:36:05] DEBUG[4300] chan_sip.c: -- Bridged call to transferee: DAHDI/3-1 State Up [May 24 12:36:05] DEBUG[4300] chan_sip.c: -- No target second channel --- [May 24 12:36:05] DEBUG[4300] chan_sip.c: -- END Sip transfer:-------------------- [May 24 12:36:05] DEBUG[4300] chan_sip.c: SIP transfer: Four channels to handle [May 24 12:36:05] DEBUG[4300] chan_sip.c: SIP transfer: trying to masquerade DAHDI/3-1 into SIP/61-00000007 [May 24 12:36:05] DEBUG[4300] channel.c: Planning to masquerade channel DAHDI/3-1 into the structure of SIP/61-00000007 [May 24 12:36:05] DEBUG[4300] channel.c: Done planning to masquerade channel DAHDI/3-1 into the structure of SIP/61-00000007 [May 24 12:36:05] DEBUG[4300] chan_sip.c: SIP transfer: Succeeded to masquerade channels. [May 24 12:36:05] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:36:05] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:36:05] DEBUG[4300] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:36:05] DEBUG[4310] channel.c: Actually Masquerading DAHDI/3-1(6) into the structure of SIP/61-00000007(6) [May 24 12:36:05] DEBUG[4310] chan_sip.c: SIP Fixup: New owner for dialogue 51b6f385-47abd4a6-d26d1e5f@192.168.77.55: DAHDI/3-1 (Old parent: DAHDI/3-1) [May 24 12:36:05] DEBUG[4310] chan_sip.c: Hangup call DAHDI/3-1, SIP callid 51b6f385-47abd4a6-d26d1e5f@192.168.77.55 [May 24 12:36:05] DEBUG[4310] chan_sip.c: Updating call counter for incoming call [May 24 12:36:05] DEBUG[4310] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fc6618' [May 24 12:36:05] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:05] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:05] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 2 (In use) [May 24 12:36:05] DEBUG[4293] devicestate.c: device 'SIP/61' state '2' [May 24 12:36:05] DEBUG[4310] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:36:05] DEBUG[4310] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:36:05] DEBUG[4310] chan_sip.c: Trying to put 'BYE sip:61@' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:36:05] DEBUG[4310] channel.c: Putting channel DAHDI/3-1 in ulaw/ulaw formats [May 24 12:36:05] DEBUG[4310] chan_dahdi.c: New owner for channel 3 is DAHDI/3-1 [May 24 12:36:05] DEBUG[4310] chan_dahdi.c: Updated conferencing on 3, with 0 conference users [May 24 12:36:05] DEBUG[4310] sig_analog.c: New owner for channel 3 is DAHDI/3-1 [May 24 12:36:05] DEBUG[4310] sig_analog.c: Updated conferencing on 3, with 0 conference users [May 24 12:36:05] DEBUG[4310] chan_dahdi.c: Updated conferencing on 3, with 0 conference users [May 24 12:36:05] DEBUG[4310] channel.c: Released clone lock on 'SIP/61-00000007' [May 24 12:36:05] DEBUG[4310] channel.c: Done Masquerading DAHDI/3-1 (6) [May 24 12:36:05] DEBUG[4310] chan_dahdi.c: Requested indication 26 on channel DAHDI/3-1 [May 24 12:36:05] DEBUG[4311] channel.c: Bridge stops because we're zombie or need a soft hangup: c0=SIP/61-00000007, c1=SIP/61-00000004, flags: Yes,Yes,No,No [May 24 12:36:05] DEBUG[4300] chan_dahdi.c: Requested indication 17 on channel DAHDI/3-1 [May 24 12:36:05] DEBUG[4311] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 24 12:36:05] DEBUG[4311] channel.c: Bridge stops bridging channels SIP/61-00000007 and SIP/61-00000004 [May 24 12:36:05] DEBUG[4311] channel.c: Hanging up channel 'SIP/61-00000004' [May 24 12:36:05] DEBUG[4311] chan_sip.c: Updating call counter for outgoing call [May 24 12:36:05] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:05] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:05] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 1 (Not in use) [May 24 12:36:05] DEBUG[4293] devicestate.c: device 'SIP/61' state '1' [May 24 12:36:05] DEBUG[4311] chan_sip.c: SIP Transfer: Not hanging up right now... Rescheduling hangup for 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060. [May 24 12:36:05] DEBUG[4310] chan_dahdi.c: Requested indication 22 on channel DAHDI/3-1 [May 24 12:36:05] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:05] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:05] DEBUG[4310] chan_dahdi.c: Requested indication 22 on channel DAHDI/2-1 [May 24 12:36:05] DEBUG[4311] app_dial.c: Exiting with DIALSTATUS=ANSWER. [May 24 12:36:05] DEBUG[4311] pbx.c: Spawn extension (external,s,3) exited non-zero on 'SIP/61-00000007' [May 24 12:36:05] VERBOSE[4311] pbx.c: == Spawn extension (external, s, 3) exited non-zero on 'SIP/61-00000007' [May 24 12:36:05] DEBUG[4311] channel.c: Soft-Hanging up channel 'SIP/61-00000007' [May 24 12:36:05] DEBUG[4311] channel.c: Hanging up zombie 'SIP/61-00000007' [May 24 12:36:05] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 1 (Not in use) [May 24 12:36:05] DEBUG[4293] devicestate.c: device 'SIP/61' state '1' [May 24 12:36:05] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:05] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:05] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 1 (Not in use) [May 24 12:36:05] DEBUG[4293] devicestate.c: device 'SIP/61' state '1' [May 24 12:36:05] DEBUG[4309] bridging.c: Giving bridge technology multiplexed_bridge notification that 0xb79b2998 is leaving bridge 0xb7dbdb20 [May 24 12:36:05] DEBUG[4309] bridge_multiplexed.c: Removing channel 'DAHDI/2-1' from multiplexed thread '0xb7dbdb90' [May 24 12:36:05] DEBUG[4309] bridging.c: Removed channel 0x9fc8bb8 from bridge array on 0xb7dbdb20, new count is 1 [May 24 12:36:05] DEBUG[4309] bridging.c: Bridge 0xb7dbdb20 channel count (1) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [May 24 12:36:05] DEBUG[4309] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [May 24 12:36:05] VERBOSE[4309] file.c: -- Playing 'en/beep.slin' (language 'en') [May 24 12:36:05] DEBUG[4315] bridging.c: Joining bridge channel 0xb7dbc538 to bridge 0xb7dbdb20 [May 24 12:36:05] DEBUG[4315] bridging.c: Added channel Bridge/0xb7dbd8e8-output(0xb7db9e78) to bridge array on 0xb7dbdb20, new count is 2 [May 24 12:36:05] DEBUG[4315] bridging.c: Bridge 0xb7dbdb20 channel count (2) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [May 24 12:36:05] DEBUG[4315] bridging.c: Bridge 0xb7dbdb20 is happy that channel Bridge/0xb7dbd8e8-output already has read format slin [May 24 12:36:05] DEBUG[4315] bridging.c: Bridge 0xb7dbdb20 is happy that channel Bridge/0xb7dbd8e8-output already has write format slin [May 24 12:36:05] DEBUG[4315] bridging.c: Giving bridge technology multiplexed_bridge notification that 0xb7dbc538 is joining bridge 0xb7dbdb20 [May 24 12:36:05] DEBUG[4315] bridge_multiplexed.c: Adding channel 'Bridge/0xb7dbd8e8-output' to multiplexed thread '0xb7dbdb90' for monitoring [May 24 12:36:05] DEBUG[4315] channel.c: Set channel DAHDI/3-1 to read format slin [May 24 12:36:05] DEBUG[4315] channel.c: Set channel DAHDI/3-1 to write format slin [May 24 12:36:05] DEBUG[4315] bridging.c: Going into a single threaded signal wait for bridge channel 0xb7dbc538 of bridge 0xb7dbdb20 [May 24 12:36:05] DEBUG[4300] chan_sip.c: = Looking for Call ID: 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 (Checking To) --From tag as63939bc3 --To-tag 1C7DB0CA-E321C3E3 [May 24 12:36:05] DEBUG[4300] chan_sip.c: Stopping retransmission on '0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060' of Request 103: Match Found [May 24 12:36:05] DEBUG[4300] chan_sip.c: = Looking for Call ID: 51b6f385-47abd4a6-d26d1e5f@192.168.77.55 (Checking To) --From tag as3212d3fc --To-tag 852099F1-F1B28732 [May 24 12:36:05] DEBUG[4300] chan_sip.c: Stopping retransmission on '51b6f385-47abd4a6-d26d1e5f@192.168.77.55' of Request 102: Match Found [May 24 12:36:05] DEBUG[4300] chan_sip.c: Destroying SIP dialog 51b6f385-47abd4a6-d26d1e5f@192.168.77.55 [May 24 12:36:05] DEBUG[4300] rtp_engine.c: Destroyed RTP instance '0x9fc6618' [May 24 12:36:05] DEBUG[4300] chan_sip.c: = Looking for Call ID: 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 (Checking From) --From tag 1C7DB0CA-E321C3E3 --To-tag as63939bc3 [May 24 12:36:05] DEBUG[4300] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [May 24 12:36:05] DEBUG[4300] netsock2.c: Splitting '192.168.77.55' gives... [May 24 12:36:05] DEBUG[4300] netsock2.c: ...host '192.168.77.55' and port '(null)'. [May 24 12:36:05] DEBUG[4300] chan_sip.c: Setting SIP_ALREADYGONE on dialog 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 [May 24 12:36:05] DEBUG[4300] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9fbb168' [May 24 12:36:05] DEBUG[4300] chan_sip.c: Received bye, no owner, selfdestruct soon. [May 24 12:36:05] DEBUG[4300] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.77.55:5060 [May 24 12:36:05] DEBUG[4309] channel.c: Scheduling timer at (364 requested / 364 actual) timer ticks per second [May 24 12:36:05] DEBUG[4309] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 24 12:36:05] DEBUG[4309] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 24 12:36:05] DEBUG[4309] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 24 12:36:05] DEBUG[4309] app_confbridge.c: Departing underlying channel 'Bridge/0xb7dbd8e8-output' from bridge '0xb7dbdb20' [May 24 12:36:05] DEBUG[4315] bridging.c: Giving bridge technology multiplexed_bridge notification that 0xb7dbc538 is leaving bridge 0xb7dbdb20 [May 24 12:36:05] DEBUG[4315] bridge_multiplexed.c: Removing channel 'Bridge/0xb7dbd8e8-output' from multiplexed thread '0xb7dbdb90' [May 24 12:36:05] DEBUG[4315] bridging.c: Removed channel 0xb7db9e78 from bridge array on 0xb7dbdb20, new count is 1 [May 24 12:36:05] DEBUG[4315] bridging.c: Bridge 0xb7dbdb20 channel count (1) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [May 24 12:36:05] DEBUG[4309] pbx.c: Extension 26, priority 4 returned normally even though call was hung up [May 24 12:36:05] DEBUG[4309] channel.c: Soft-Hanging up channel 'DAHDI/2-1' [May 24 12:36:05] DEBUG[4309] channel.c: Hanging up channel 'DAHDI/2-1' [May 24 12:36:05] DEBUG[4309] chan_dahdi.c: dahdi_hangup(DAHDI/2-1) [May 24 12:36:05] DEBUG[4309] sig_analog.c: analog_hangup 2 [May 24 12:36:05] DEBUG[4309] sig_analog.c: Hangup: channel: 2 index = 0, normal = 1, callwait = 0, thirdcall = 0 [May 24 12:36:05] DEBUG[4309] chan_dahdi.c: Disabled echo cancellation on channel 2 [May 24 12:36:05] DEBUG[4309] chan_dahdi.c: Set option TONE VERIFY, mode: OFF(0) on DAHDI/2-1 [May 24 12:36:05] DEBUG[4309] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/2-1 [May 24 12:36:05] DEBUG[4309] sig_analog.c: Updated conferencing on 2, with 0 conference users [May 24 12:36:05] VERBOSE[4309] sig_analog.c: -- Hanging up on 'DAHDI/2-1' [May 24 12:36:05] VERBOSE[4309] chan_dahdi.c: -- Hungup 'DAHDI/2-1' [May 24 12:36:05] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for DAHDI - 2 [May 24 12:36:05] DEBUG[4293] devicestate.c: Changing state for DAHDI/2 - state 0 (Unknown) [May 24 12:36:05] DEBUG[4293] devicestate.c: device 'DAHDI/2' state '0' [May 24 12:36:22] DEBUG[4299] res_jabber.c: XML parsing successful [May 24 12:36:23] DEBUG[4300] chan_sip.c: Auto destroying SIP dialog '59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060' [May 24 12:36:23] DEBUG[4300] chan_sip.c: Destroying SIP dialog 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 [May 24 12:36:23] DEBUG[4300] chan_sip.c: Updating call counter for outgoing call [May 24 12:36:23] DEBUG[4300] chan_sip.c: This call did not properly clean up call limits. Call ID 59e16c9d078057ef3ebd613024bd806e@192.168.77.20:5060 [May 24 12:36:23] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:23] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:23] DEBUG[4300] rtp_engine.c: Destroyed RTP instance '0x9fa6338' [May 24 12:36:23] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 1 (Not in use) [May 24 12:36:23] DEBUG[4293] devicestate.c: device 'SIP/61' state '1' [May 24 12:36:25] VERBOSE[4288] asterisk.c: Waiting for inactivity to perform halt... [May 24 12:36:37] DEBUG[4300] chan_sip.c: Auto destroying SIP dialog '0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060' [May 24 12:36:37] DEBUG[4300] chan_sip.c: Destroying SIP dialog 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 [May 24 12:36:37] DEBUG[4300] chan_sip.c: Updating call counter for outgoing call [May 24 12:36:37] DEBUG[4300] chan_sip.c: This call did not properly clean up call limits. Call ID 0c97da9d731178fe6dd03dce75385be3@192.168.77.20:5060 [May 24 12:36:37] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for SIP - 61 [May 24 12:36:37] DEBUG[4293] chan_sip.c: Checking device state for peer 61 [May 24 12:36:37] DEBUG[4300] rtp_engine.c: Destroyed RTP instance '0x9fbb168' [May 24 12:36:37] DEBUG[4293] devicestate.c: Changing state for SIP/61 - state 1 (Not in use) [May 24 12:36:37] DEBUG[4293] devicestate.c: device 'SIP/61' state '1' [May 24 12:36:51] DEBUG[4310] sig_analog.c: analog_exception 3 [May 24 12:36:51] DEBUG[4310] sig_analog.c: Exception on 13, channel 3 [May 24 12:36:51] DEBUG[4310] sig_analog.c: __analog_handle_event 3 [May 24 12:36:51] DEBUG[4310] sig_analog.c: Got event ANALOG_EVENT_POLARITY(11) on channel 3 (index 0) [May 24 12:36:51] DEBUG[4310] sig_analog.c: Ignore Hangup on polarity switch, channel 3 [May 24 12:36:51] DEBUG[4310] sig_analog.c: Polarity Reversal event occured - DEBUG 2: channel 3, state 6, pol= 0, aonp= 0, honp= 0, pdelay= 600, tv= 595753211 [May 24 12:36:51] DEBUG[4310] sig_analog.c: analog_exception 3 [May 24 12:36:51] DEBUG[4310] sig_analog.c: Exception on 13, channel 3 [May 24 12:36:51] DEBUG[4310] sig_analog.c: __analog_handle_event 3 [May 24 12:36:51] DEBUG[4310] sig_analog.c: Got event ANALOG_EVENT_ONHOOK(1) on channel 3 (index 0) [May 24 12:36:51] DEBUG[4310] chan_dahdi.c: Disabled echo cancellation on channel 3 [May 24 12:36:51] DEBUG[4312] bridging.c: Giving bridge technology multiplexed_bridge notification that 0xb793a998 is leaving bridge 0xb7dbdb20 [May 24 12:36:51] DEBUG[4312] bridge_multiplexed.c: Removing channel 'DAHDI/3-1' from multiplexed thread '0xb7dbdb90' [May 24 12:36:51] DEBUG[4310] bridge_multiplexed.c: Stopping actual thread for multiplexed thread '0xb7dbdb90' [May 24 12:36:51] DEBUG[4312] bridging.c: Removed channel 0xb7dbcf98 from bridge array on 0xb7dbdb20, new count is 0 [May 24 12:36:51] DEBUG[4312] bridging.c: Bridge 0xb7dbdb20 channel count (0) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [May 24 12:36:51] DEBUG[4312] bridging.c: Bridge is returning 0xb793a998 to read format ulaw(4) [May 24 12:36:51] DEBUG[4312] channel.c: Set channel DAHDI/3-1 to read format ulaw [May 24 12:36:51] DEBUG[4312] bridging.c: Bridge is returning 0xb793a998 to write format ulaw(4) [May 24 12:36:51] DEBUG[4312] channel.c: Set channel DAHDI/3-1 to write format ulaw [May 24 12:36:51] DEBUG[4312] devicestate.c: device 'confbridge:26' state '1' [May 24 12:36:51] DEBUG[4312] app_confbridge.c: Destroying conference bridge '26' [May 24 12:36:51] DEBUG[4312] channel.c: Hanging up channel 'Bridge/0xb7dbd8e8-output' [May 24 12:36:51] WARNING[4312] cdr.c: CDR on channel 'Bridge/0xb7dbd8e8-output' has no answer time but is 'ANSWERED' [May 24 12:36:51] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for Bridge - 0xb7dbd8e8 [May 24 12:36:51] DEBUG[4293] devicestate.c: Changing state for Bridge/0xb7dbd8e8 - state 0 (Unknown) [May 24 12:36:51] DEBUG[4293] devicestate.c: device 'Bridge/0xb7dbd8e8' state '0' [May 24 12:36:51] DEBUG[4312] channel.c: Hanging up channel 'Bridge/0xb7dbd8e8-input' [May 24 12:36:51] WARNING[4312] cdr.c: CDR on channel 'Bridge/0xb7dbd8e8-input' has no answer time but is 'ANSWERED' [May 24 12:36:51] DEBUG[4312] bridging.c: Telling all channels in bridge 0xb7dbdb20 to end and leave the party [May 24 12:36:51] DEBUG[4293] devicestate.c: No provider found, checking channel drivers for Bridge - 0xb7dbd8e8 [May 24 12:36:51] DEBUG[4293] devicestate.c: Changing state for Bridge/0xb7dbd8e8 - state 0 (Unknown) [May 24 12:36:51] DEBUG[4293] devicestate.c: device 'Bridge/0xb7dbd8e8' state '0' [May 24 12:36:51] DEBUG[4312] bridging.c: Actually destroying bridge 0xb7dbdb20, nobody wants it anymore [May 24 12:36:51] DEBUG[4312] bridging.c: Giving bridge technology multiplexed_bridge the bridge structure 0xb7dbdb20 to destroy [May 24 12:36:51] DEBUG[4312] bridge_multiplexed.c: Unlinking multiplexed thread '0xb7dbdb90' since nobody is using it anymore [May 24 12:36:51] DEBUG[4312] pbx.c: Extension 26, priority 4 returned normally even though call was hung up [May 24 12:36:51] DEBUG[4312] channel.c: Soft-Hanging up channel 'DAHDI/3-1' [May 24 12:36:51] DEBUG[4312] channel.c: Hanging up channel 'DAHDI/3-1' [May 24 12:36:51] DEBUG[4312] chan_dahdi.c: dahdi_hangup(DAHDI/3-1) [May 24 12:36:51] DEBUG[4312] sig_analog.c: analog_hangup 3 [May 24 12:36:51] DEBUG[4312] sig_analog.c: Hangup: channel: 3 index = 0, normal = 1, callwait = 0, thirdcall = 0 [May 24 12:36:51] DEBUG[4312] chan_dahdi.c: Set option TONE VERIFY, mode: OFF(0) on DAHDI/3-1 [May 24 12:36:51] DEBUG[4312] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/3-1 [May 24 12:36:51] DEBUG[4312] sig_analog.c: Updated conferencing on 3, with 0 conference users [May 24 12:36:51] VERBOSE[4312] sig_analog.c: -- Hanging up on 'DAHDI/3-1' [May 24 12:36:51] VERBOSE[4312] chan_dahdi.c: -- Hungup 'DAHDI/3-1'