[Feb 15 09:12:54] DEBUG[27512] chan_sip.c: = Looking for Call ID: 874e699a-c7144523-ca45b368@10.10.5.226 (Checking From) --From tag B9A83ECE-F27A0707 --To-tag [Feb 15 09:12:54] DEBUG[27512] logger.c: CALL_ID [C-00000000] created by thread. [Feb 15 09:12:54] DEBUG[27512] acl.c: For destination '10.10.5.64', our source address is '10.10.5.162'. [Feb 15 09:12:54] DEBUG[27512] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 10.10.5.162:5060 [Feb 15 09:12:54] DEBUG[27512] chan_sip.c: Allocating new SIP dialog for 874e699a-c7144523-ca45b368@10.10.5.226 - INVITE (No RTP) [Feb 15 09:12:54] DEBUG[27512][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Feb 15 09:12:54] DEBUG[27512][C-00000000] sip/reqresp_parser.c: Begin: parsing SIP "Supported: 100rel,replaces" [Feb 15 09:12:54] DEBUG[27512][C-00000000] sip/reqresp_parser.c: Found SIP option: -100rel- [Feb 15 09:12:54] DEBUG[27512][C-00000000] sip/reqresp_parser.c: Matched SIP option: 100rel [Feb 15 09:12:54] DEBUG[27512][C-00000000] sip/reqresp_parser.c: Found SIP option: -replaces- [Feb 15 09:12:54] DEBUG[27512][C-00000000] sip/reqresp_parser.c: Matched SIP option: replaces [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: Splitting '10.10.5.64:5060' into... [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: ...host '10.10.5.64' and port '5060'. [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: Splitting 'si.unimib.it' into... [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: ...host 'si.unimib.it' and port ''. [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x89ba68c' [Feb 15 09:12:54] DEBUG[27512][C-00000000] res_rtp_asterisk.c: Allocated port 8314 for RTP instance '0x89ba68c' [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: Splitting '10.10.5.162' into... [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: ...host '10.10.5.162' and port ''. [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: RTP instance '0x89ba68c' is setup and ready to go [Feb 15 09:12:54] DEBUG[27512][C-00000000] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x89ba68c' [Feb 15 09:12:54] VERBOSE[27512][C-00000000] netsock2.c: == Using SIP RTP CoS mark 5 [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Setting NAT on RTP to Off [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP o=- 1360887948 1360887948 IN IP4 10.10.5.226... OK. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED OR FAILED. [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: Splitting '10.10.5.226' into... [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: ...host '10.10.5.226' and port ''. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP c=IN IP4 10.10.5.226... OK. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP a=sendrecv... OK. [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: Setting payload 9 based on m type on 0xb4a53dac [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: Setting payload 0 based on m type on 0xb4a53dac [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: Setting payload 8 based on m type on 0xb4a53dac [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: Setting payload 18 based on m type on 0xb4a53dac [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: Setting payload 101 based on m type on 0xb4a53dac [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Feb 15 09:12:54] DEBUG[27512][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x89ba68c' [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: Copying payload 0 from 0xb4a53dac to 0x89ba838 [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: Copying payload 8 from 0xb4a53dac to 0x89ba838 [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: Copying payload 9 from 0xb4a53dac to 0x89ba838 [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: Copying payload 18 from 0xb4a53dac to 0x89ba838 [Feb 15 09:12:54] DEBUG[27512][C-00000000] rtp_engine.c: Copying payload 101 from 0xb4a53dac to 0x89ba838 [Feb 15 09:12:54] DEBUG[27512][C-00000000] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x89ba68c' [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: We're settling with these formats: (ulaw|alaw|g722) [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Checking SIP call limits for device [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Updating call counter for incoming call [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: Splitting '10.10.5.162' into... [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: ...host '10.10.5.162' and port ''. [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: Splitting 'si.unimib.it' into... [Feb 15 09:12:54] DEBUG[27512][C-00000000] netsock2.c: ...host 'si.unimib.it' and port ''. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: *** Our native formats are (alaw) [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: *** Joint capabilities are (ulaw|alaw|g722) [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: *** Our capabilities are (gsm|ulaw|alaw|g722) [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: This channel will not be able to handle video. [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: build_route: Record-Route hop: [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: SIP/proxysiptest-00000000: New call is still down.... Trying... [Feb 15 09:12:54] DEBUG[27512][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.10.5.64:5060 [Feb 15 09:12:54] DEBUG[27512][C-00000000] logger.c: Call_ID [C-00000000] being removed from thread. [Feb 15 09:12:54] DEBUG[27552][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread. [Feb 15 09:12:54] DEBUG[27498] devicestate.c: No provider found, checking channel drivers for SIP - proxysiptest [Feb 15 09:12:54] DEBUG[27498] chan_sip.c: Checking device state for peer proxysiptest [Feb 15 09:12:54] DEBUG[27498] devicestate.c: Changing state for SIP/proxysiptest - state 1 (Not in use) [Feb 15 09:12:54] DEBUG[27498] devicestate.c: device 'SIP/proxysiptest' state '1' [Feb 15 09:12:54] DEBUG[27531] app_queue.c: Device 'SIP/proxysiptest' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Launching 'NoCDR' [Feb 15 09:12:54] VERBOSE[27552][C-00000000] pbx.c: -- Executing [2000@sipincoming:1] NoCDR("SIP/proxysiptest-00000000", "") in new stack [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Function result is '"Prove5" <2025>' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Function result is 'Prove5' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Function result is '2025' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Function result is 'allowed_passed_screen' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Result of 'EXTEN' is '2000' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Launching 'NoOp' [Feb 15 09:12:54] VERBOSE[27552][C-00000000] pbx.c: -- Executing [2000@sipincoming:2] NoOp("SIP/proxysiptest-00000000", "Chiamata da "Prove5" <2025> verso 2000 ") in new stack [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Function result is 'inbound' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Launching 'Set' [Feb 15 09:12:54] VERBOSE[27552][C-00000000] pbx.c: -- Executing [2000@sipincoming:3] Set("SIP/proxysiptest-00000000", "domain=inbound") in new stack [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Function result is '2025' [Feb 15 09:12:54] DEBUG[27552][C-00000000] func_strings.c: FUNCTION REGEX ([a-zA-Z])("2025") [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Function result is '0' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Launching 'Set' [Feb 15 09:12:54] VERBOSE[27552][C-00000000] pbx.c: -- Executing [2000@sipincoming:4] Set("SIP/proxysiptest-00000000", "val=0") in new stack [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Result of 'val' is '0' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Expression result is '0' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Launching 'GotoIf' [Feb 15 09:12:54] VERBOSE[27552][C-00000000] pbx.c: -- Executing [2000@sipincoming:5] GotoIf("SIP/proxysiptest-00000000", "0?emptycallerid") in new stack [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Not taking any branch [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Result of 'domain' is 'inbound' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Expression result is '1' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Launching 'GotoIf' [Feb 15 09:12:54] VERBOSE[27552][C-00000000] pbx.c: -- Executing [2000@sipincoming:6] GotoIf("SIP/proxysiptest-00000000", "1?call") in new stack [Feb 15 09:12:54] VERBOSE[27552][C-00000000] pbx.c: -- Goto (sipincoming,2000,9) [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Result of 'EXTEN' is '2000' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Function result is '2025' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Launching 'Macro' [Feb 15 09:12:54] VERBOSE[27552][C-00000000] pbx.c: -- Executing [2000@sipincoming:9] Macro("SIP/proxysiptest-00000000", "MD110Call,2000,2025)") in new stack [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Result of 'TRUNKQsig' is 'dahdi/g1' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Result of 'ARG1' is '2000' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Result of 'RINGTIMESIPTOLEGACYINTERNI' is '35' [Feb 15 09:12:54] DEBUG[27552][C-00000000] pbx.c: Launching 'Dial' [Feb 15 09:12:54] VERBOSE[27552][C-00000000] pbx.c: -- Executing [s@macro-MD110Call:1] Dial("SIP/proxysiptest-00000000", "dahdi/g1/2000,35,g") in new stack [Feb 15 09:12:54] DEBUG[27552][C-00000000] chan_dahdi.c: Using channel 94 [Feb 15 09:12:54] DEBUG[27552][C-00000000] sig_pri.c: sig_pri_request 94 [Feb 15 09:12:54] DEBUG[27552][C-00000000] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [Feb 15 09:12:54] DEBUG[27552][C-00000000] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [Feb 15 09:12:54] DEBUG[27498] devicestate.c: No provider found, checking channel drivers for DAHDI - i4/2000 [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel_internal_api.c: Channel Call ID changing from [C-00000000] to [C-00000000] [Feb 15 09:12:54] DEBUG[27552][C-00000000] rtp_engine.c: Can't find native functions for channel 'DAHDI/i4/2000-1' [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable DIALEDTIME. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable ANSWEREDTIME. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable DIALEDPEERNAME. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable DIALEDPEERNUMBER. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable DIALSTATUS. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable MACRO_DEPTH. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable ARG2. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable ARG1. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable MACRO_PRIORITY. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable MACRO_CONTEXT. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable MACRO_EXTEN. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable val. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable domain. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable SIPCALLID. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable SIPDOMAIN. [Feb 15 09:12:54] DEBUG[27552][C-00000000] channel.c: Not copying variable SIPURI. [Feb 15 09:12:54] DEBUG[27552][C-00000000] sig_pri.c: CALLER NAME: Prove5 NUM: 2025 [Feb 15 09:12:54] DEBUG[27552][C-00000000] sig_pri.c: prioffset: 1 mastertrunkgroup: 0 logicalspan: 0 result: 1 [Feb 15 09:12:54] VERBOSE[27552][C-00000000] sig_pri.c: -- Requested transfer capability: 0x00 - SPEECH [Feb 15 09:12:54] VERBOSE[27552][C-00000000] app_dial.c: -- Called dahdi/g1/2000 [Feb 15 09:12:54] DEBUG[27498] devicestate.c: Changing state for DAHDI/i4/2000 - state 2 (In use) [Feb 15 09:12:54] DEBUG[27498] devicestate.c: device 'DAHDI/i4/2000' state '2' [Feb 15 09:12:54] DEBUG[27498] devicestate.c: No provider found, checking channel drivers for DAHDI - i4/2000 [Feb 15 09:12:54] DEBUG[27498] devicestate.c: Changing state for DAHDI/i4/2000 - state 2 (In use) [Feb 15 09:12:54] DEBUG[27498] devicestate.c: device 'DAHDI/i4/2000' state '2' [Feb 15 09:12:54] DEBUG[27531] app_queue.c: Device 'DAHDI/i4/2000' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 15 09:12:54] DEBUG[27531] app_queue.c: Device 'DAHDI/i4/2000' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 15 09:12:54] DEBUG[27509][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread. [Feb 15 09:12:54] DEBUG[27509][C-00000000] logger.c: Call_ID [C-00000000] being removed from thread. [Feb 15 09:12:54] VERBOSE[27552][C-00000000] app_dial.c: -- DAHDI/i4/2000-1 is making progress passing it to SIP/proxysiptest-00000000 [Feb 15 09:12:54] DEBUG[27552][C-00000000] chan_sip.c: Setting framing from config on incoming call [Feb 15 09:12:54] DEBUG[27552][C-00000000] chan_sip.c: ** Our capability: (ulaw|alaw|g722) Video flag: True Text flag: True [Feb 15 09:12:54] DEBUG[27552][C-00000000] chan_sip.c: ** Our prefcodec: (nothing) [Feb 15 09:12:54] DEBUG[27552][C-00000000] chan_sip.c: -- Done with adding codecs to SDP [Feb 15 09:12:54] DEBUG[27552][C-00000000] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw|g722) [Feb 15 09:12:54] DEBUG[27552][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 183' onto UDP socket destined for 10.10.5.64:5060 [Feb 15 09:12:54] DEBUG[27509][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread. [Feb 15 09:12:54] DEBUG[27509][C-00000000] sig_pri.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 4 [Feb 15 09:12:54] DEBUG[27509][C-00000000] logger.c: Call_ID [C-00000000] being removed from thread. [Feb 15 09:12:54] VERBOSE[27552][C-00000000] app_dial.c: -- DAHDI/i4/2000-1 is proceeding passing it to SIP/proxysiptest-00000000 [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160 [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x89ba68c' [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- start learning mode pass with addr = 10.10.5.226:8014 [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- probation = 4, seq = 14976 [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- Condition for learning hasn't exited, so reject the frame. [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- start learning mode pass with addr = 10.10.5.226:8014 [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- probation = 3, seq = 14977 [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- Condition for learning hasn't exited, so reject the frame. [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- start learning mode pass with addr = 10.10.5.226:8014 [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- probation = 2, seq = 14978 [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- Condition for learning hasn't exited, so reject the frame. [Feb 15 09:12:54] DEBUG[27509][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread. [Feb 15 09:12:54] DEBUG[27509][C-00000000] chan_dahdi.c: Enabled echo cancellation on channel 94 [Feb 15 09:12:54] DEBUG[27509][C-00000000] logger.c: Call_ID [C-00000000] being removed from thread. [Feb 15 09:12:54] DEBUG[27498] devicestate.c: No provider found, checking channel drivers for DAHDI - i4/2000 [Feb 15 09:12:54] VERBOSE[27552][C-00000000] app_dial.c: -- DAHDI/i4/2000-1 is ringing [Feb 15 09:12:54] DEBUG[27552][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 10.10.5.64:5060 [Feb 15 09:12:54] DEBUG[27498] devicestate.c: Changing state for DAHDI/i4/2000 - state 6 (Ringing) [Feb 15 09:12:54] DEBUG[27498] devicestate.c: device 'DAHDI/i4/2000' state '6' [Feb 15 09:12:54] DEBUG[27531] app_queue.c: Device 'DAHDI/i4/2000' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- start learning mode pass with addr = 10.10.5.226:8014 [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- probation = 1, seq = 14979 [Feb 15 09:12:54] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0x89bf5e0 -- Probation Ended. Set strict_rtp_state to STRICT_RTP_CLOSED with address 10.10.5.226:8014 [Feb 15 09:12:56] DEBUG[27509][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread. [Feb 15 09:12:56] DEBUG[27509][C-00000000] chan_dahdi.c: Echo cancellation already on [Feb 15 09:12:56] DEBUG[27509][C-00000000] logger.c: Call_ID [C-00000000] being removed from thread. [Feb 15 09:12:56] VERBOSE[27552][C-00000000] app_dial.c: -- DAHDI/i4/2000-1 answered SIP/proxysiptest-00000000 [Feb 15 09:12:56] DEBUG[27498] devicestate.c: No provider found, checking channel drivers for DAHDI - i4/2000 [Feb 15 09:12:56] DEBUG[27498] devicestate.c: Changing state for DAHDI/i4/2000 - state 2 (In use) [Feb 15 09:12:56] DEBUG[27498] devicestate.c: device 'DAHDI/i4/2000' state '2' [Feb 15 09:12:56] DEBUG[27552][C-00000000] chan_sip.c: SIP answering channel: SIP/proxysiptest-00000000 [Feb 15 09:12:56] DEBUG[27498] devicestate.c: No provider found, checking channel drivers for SIP - proxysiptest [Feb 15 09:12:56] DEBUG[27552][C-00000000] res_rtp_asterisk.c: Setting the marker bit due to a source update [Feb 15 09:12:56] DEBUG[27498] chan_sip.c: Checking device state for peer proxysiptest [Feb 15 09:12:56] DEBUG[27498] devicestate.c: Changing state for SIP/proxysiptest - state 1 (Not in use) [Feb 15 09:12:56] DEBUG[27498] devicestate.c: device 'SIP/proxysiptest' state '1' [Feb 15 09:12:56] DEBUG[27531] app_queue.c: Device 'DAHDI/i4/2000' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Feb 15 09:12:56] DEBUG[27531] app_queue.c: Device 'SIP/proxysiptest' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 15 09:12:56] DEBUG[27552][C-00000000] chan_sip.c: Setting framing from config on incoming call [Feb 15 09:12:56] DEBUG[27552][C-00000000] chan_sip.c: ** Our capability: (ulaw|alaw|g722) Video flag: True Text flag: True [Feb 15 09:12:56] DEBUG[27552][C-00000000] chan_sip.c: ** Our prefcodec: (nothing) [Feb 15 09:12:56] DEBUG[27552][C-00000000] chan_sip.c: -- Done with adding codecs to SDP [Feb 15 09:12:56] DEBUG[27552][C-00000000] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw|g722) [Feb 15 09:12:56] DEBUG[27552][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.10.5.64:5060 [Feb 15 09:12:56] DEBUG[27552][C-00000000] features.c: Removing dialed interfaces datastore on DAHDI/i4/2000-1 since we're bridging [Feb 15 09:12:56] DEBUG[27552][C-00000000] res_rtp_asterisk.c: Setting the marker bit due to a source update [Feb 15 09:12:56] DEBUG[27552][C-00000000] chan_dahdi.c: Requested indication 20 on channel DAHDI/i4/2000-1 [Feb 15 09:12:56] DEBUG[27512] chan_sip.c: = Looking for Call ID: 874e699a-c7144523-ca45b368@10.10.5.226 (Checking From) --From tag B9A83ECE-F27A0707 --To-tag as4d48411a [Feb 15 09:12:56] DEBUG[27512][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread. [Feb 15 09:12:56] DEBUG[27512][C-00000000] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Feb 15 09:12:56] DEBUG[27512][C-00000000] chan_sip.c: Stopping retransmission on '874e699a-c7144523-ca45b368@10.10.5.226' of Response 2: Match Found [Feb 15 09:12:56] DEBUG[27512][C-00000000] logger.c: Call_ID [C-00000000] being removed from thread. [Feb 15 09:12:57] DEBUG[27512] chan_sip.c: = Looking for Call ID: d2e101b5-f3d011c2-91986fd3@10.10.5.225 (Checking From) --From tag AC50AA29-29115746 --To-tag [Feb 15 09:12:57] DEBUG[27512] logger.c: CALL_ID [C-00000001] created by thread. [Feb 15 09:12:57] DEBUG[27512] acl.c: For destination '10.10.5.64', our source address is '10.10.5.162'. [Feb 15 09:12:57] DEBUG[27512] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 10.10.5.162:5060 [Feb 15 09:12:57] DEBUG[27512] chan_sip.c: Allocating new SIP dialog for d2e101b5-f3d011c2-91986fd3@10.10.5.225 - INVITE (No RTP) [Feb 15 09:12:57] DEBUG[27512][C-00000001] logger.c: CALL_ID [C-00000001] bound to thread. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Feb 15 09:12:57] DEBUG[27512][C-00000001] sip/reqresp_parser.c: Begin: parsing SIP "Supported: 100rel,replaces" [Feb 15 09:12:57] DEBUG[27512][C-00000001] sip/reqresp_parser.c: Found SIP option: -100rel- [Feb 15 09:12:57] DEBUG[27512][C-00000001] sip/reqresp_parser.c: Matched SIP option: 100rel [Feb 15 09:12:57] DEBUG[27512][C-00000001] sip/reqresp_parser.c: Found SIP option: -replaces- [Feb 15 09:12:57] DEBUG[27512][C-00000001] sip/reqresp_parser.c: Matched SIP option: replaces [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Looking for callid 874e699a-c7144523-ca45b368@10.10.5.226 (fromtag B9A83ECE-F27A0707 totag as4d48411a) [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Matched INCOMING call - their tag is B9A83ECE-F27A0707 Our tag is as4d48411a [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: Splitting '10.10.5.64:5060' into... [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: ...host '10.10.5.64' and port '5060'. [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: Splitting 'si.unimib.it' into... [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: ...host 'si.unimib.it' and port ''. [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb44afc9c' [Feb 15 09:12:57] DEBUG[27512][C-00000001] res_rtp_asterisk.c: Allocated port 8038 for RTP instance '0xb44afc9c' [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: Splitting '10.10.5.162' into... [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: ...host '10.10.5.162' and port ''. [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: RTP instance '0xb44afc9c' is setup and ready to go [Feb 15 09:12:57] DEBUG[27512][C-00000001] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb44afc9c' [Feb 15 09:12:57] VERBOSE[27512][C-00000001] netsock2.c: == Using SIP RTP CoS mark 5 [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Setting NAT on RTP to Off [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing session-level SDP o=- 1360896592 1360896592 IN IP4 10.10.5.225... OK. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED OR FAILED. [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: Splitting '10.10.5.225' into... [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: ...host '10.10.5.225' and port ''. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing session-level SDP c=IN IP4 10.10.5.225... OK. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing session-level SDP a=sendrecv... OK. [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: Setting payload 9 based on m type on 0xb4a53d3c [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: Setting payload 0 based on m type on 0xb4a53d3c [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: Setting payload 8 based on m type on 0xb4a53d3c [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: Setting payload 18 based on m type on 0xb4a53d3c [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: Setting payload 101 based on m type on 0xb4a53d3c [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Feb 15 09:12:57] DEBUG[27512][C-00000001] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb44afc9c' [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: Copying payload 0 from 0xb4a53d3c to 0xb44afe48 [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: Copying payload 8 from 0xb4a53d3c to 0xb44afe48 [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: Copying payload 9 from 0xb4a53d3c to 0xb44afe48 [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: Copying payload 18 from 0xb4a53d3c to 0xb44afe48 [Feb 15 09:12:57] DEBUG[27512][C-00000001] rtp_engine.c: Copying payload 101 from 0xb4a53d3c to 0xb44afe48 [Feb 15 09:12:57] DEBUG[27512][C-00000001] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0xb44afc9c' [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: We're settling with these formats: (ulaw|alaw|g722) [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Checking SIP call limits for device [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Updating call counter for incoming call [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: Splitting '10.10.5.162' into... [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: ...host '10.10.5.162' and port ''. [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: Splitting 'si.unimib.it' into... [Feb 15 09:12:57] DEBUG[27512][C-00000001] netsock2.c: ...host 'si.unimib.it' and port ''. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: *** Our native formats are (alaw) [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: *** Joint capabilities are (ulaw|alaw|g722) [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: *** Our capabilities are (gsm|ulaw|alaw|g722) [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: This channel will not be able to handle video. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: build_route: Record-Route hop: [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: SIP transfer: Invite Replace incoming channel should bridge to channel DAHDI/i4/2000-1 while hanging up channel SIP/proxysiptest-00000000 [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.10.5.64:5060 [Feb 15 09:12:57] DEBUG[27498] devicestate.c: No provider found, checking channel drivers for SIP - proxysiptest [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Setting framing from config on incoming call [Feb 15 09:12:57] DEBUG[27498] chan_sip.c: Checking device state for peer proxysiptest [Feb 15 09:12:57] DEBUG[27498] devicestate.c: Changing state for SIP/proxysiptest - state 1 (Not in use) [Feb 15 09:12:57] DEBUG[27498] devicestate.c: device 'SIP/proxysiptest' state '1' [Feb 15 09:12:57] DEBUG[27531] app_queue.c: Device 'SIP/proxysiptest' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: ** Our capability: (ulaw|alaw|g722) Video flag: True Text flag: True [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: ** Our prefcodec: (nothing) [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: -- Done with adding codecs to SDP [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw|g722) [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.10.5.64:5060 [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Invite/Replaces: preparing to masquerade SIP/proxysiptest-00000001 into SIP/proxysiptest-00000000 [Feb 15 09:12:57] DEBUG[27498] devicestate.c: No provider found, checking channel drivers for SIP - proxysiptest [Feb 15 09:12:57] DEBUG[27512][C-00000001] channel.c: Planning to masquerade channel SIP/proxysiptest-00000001 into the structure of SIP/proxysiptest-00000000 [Feb 15 09:12:57] DEBUG[27498] chan_sip.c: Checking device state for peer proxysiptest [Feb 15 09:12:57] DEBUG[27498] devicestate.c: Changing state for SIP/proxysiptest - state 1 (Not in use) [Feb 15 09:12:57] DEBUG[27498] devicestate.c: device 'SIP/proxysiptest' state '1' [Feb 15 09:12:57] DEBUG[27531] app_queue.c: Device 'SIP/proxysiptest' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 15 09:12:57] DEBUG[27512][C-00000001] channel.c: Done planning to masquerade channel SIP/proxysiptest-00000001 into the structure of SIP/proxysiptest-00000000 [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Invite/Replaces: Going to masquerade SIP/proxysiptest-00000001 into SIP/proxysiptest-00000000 [Feb 15 09:12:57] DEBUG[27552][C-00000000] channel.c: Actually Masquerading SIP/proxysiptest-00000001(6) into the structure of SIP/proxysiptest-00000000(6) [Feb 15 09:12:57] DEBUG[27552][C-00000000] channel.c: Putting channel SIP/proxysiptest-00000001 in alaw/alaw formats [Feb 15 09:12:57] DEBUG[27552][C-00000000] chan_sip.c: SIP Fixup: New owner for dialogue d2e101b5-f3d011c2-91986fd3@10.10.5.225: SIP/proxysiptest-00000001 (Old parent: SIP/proxysiptest-00000000) [Feb 15 09:12:57] DEBUG[27552][C-00000000] chan_sip.c: SIP Fixup: New owner for dialogue 874e699a-c7144523-ca45b368@10.10.5.226: SIP/proxysiptest-00000000 (Old parent: SIP/proxysiptest-00000001) [Feb 15 09:12:57] DEBUG[27552][C-00000000] channel.c: Done Masquerading SIP/proxysiptest-00000001 (6) [Feb 15 09:12:57] DEBUG[27552][C-00000000] chan_dahdi.c: Requested indication 26 on channel DAHDI/i4/2000-1 [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: Not changing SSRC since we haven't sent any RTP yet [Feb 15 09:12:57] DEBUG[27498] devicestate.c: No provider found, checking channel drivers for SIP - proxysiptest [Feb 15 09:12:57] DEBUG[27498] chan_sip.c: Checking device state for peer proxysiptest [Feb 15 09:12:57] DEBUG[27512][C-00000001] channel.c: Hanging up channel 'SIP/proxysiptest-00000000' [Feb 15 09:12:57] DEBUG[27498] devicestate.c: Changing state for SIP/proxysiptest - state 1 (Not in use) [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Asked to hangup channel that was not connected [Feb 15 09:12:57] DEBUG[27498] devicestate.c: device 'SIP/proxysiptest' state '1' [Feb 15 09:12:57] DEBUG[27531] app_queue.c: Device 'SIP/proxysiptest' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 15 09:12:57] DEBUG[27498] devicestate.c: No provider found, checking channel drivers for SIP - proxysiptest [Feb 15 09:12:57] DEBUG[27498] chan_sip.c: Checking device state for peer proxysiptest [Feb 15 09:12:57] DEBUG[27512][C-00000001] logger.c: Call_ID [C-00000001] being removed from thread. [Feb 15 09:12:57] DEBUG[27498] devicestate.c: Changing state for SIP/proxysiptest - state 1 (Not in use) [Feb 15 09:12:57] DEBUG[27498] devicestate.c: device 'SIP/proxysiptest' state '1' [Feb 15 09:12:57] DEBUG[27531] app_queue.c: Device 'SIP/proxysiptest' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160 [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0xb44afc9c' [Feb 15 09:12:57] DEBUG[27512] chan_sip.c: = Looking for Call ID: d2e101b5-f3d011c2-91986fd3@10.10.5.225 (Checking From) --From tag AC50AA29-29115746 --To-tag as18e36f52 [Feb 15 09:12:57] DEBUG[27512][C-00000001] logger.c: CALL_ID [C-00000001] bound to thread. [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Feb 15 09:12:57] DEBUG[27512][C-00000001] chan_sip.c: Stopping retransmission on 'd2e101b5-f3d011c2-91986fd3@10.10.5.225' of Response 2: Match Found [Feb 15 09:12:57] DEBUG[27512][C-00000001] logger.c: Call_ID [C-00000001] being removed from thread. [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- start learning mode pass with addr = 10.10.5.225:8014 [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- probation = 4, seq = 11664 [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- Condition for learning hasn't exited, so reject the frame. [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- start learning mode pass with addr = 10.10.5.225:8014 [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- probation = 3, seq = 11665 [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- Condition for learning hasn't exited, so reject the frame. [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- start learning mode pass with addr = 10.10.5.225:8014 [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- probation = 2, seq = 11666 [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- Condition for learning hasn't exited, so reject the frame. [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- start learning mode pass with addr = 10.10.5.225:8014 [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- probation = 1, seq = 11667 [Feb 15 09:12:57] DEBUG[27552][C-00000000] res_rtp_asterisk.c: 0xb44b4580 -- Probation Ended. Set strict_rtp_state to STRICT_RTP_CLOSED with address 10.10.5.225:8014 [Feb 15 09:12:59] DEBUG[27552][C-00000000] res_rtp_asterisk.c: Got RTCP report of 80 bytes [Feb 15 09:13:00] DEBUG[27512] chan_sip.c: = Looking for Call ID: 874e699a-c7144523-ca45b368@10.10.5.226 (Checking From) --From tag B9A83ECE-F27A0707 --To-tag as4d48411a [Feb 15 09:13:00] DEBUG[27512][C-00000000] logger.c: CALL_ID [C-00000000] bound to thread. [Feb 15 09:13:00] ERROR[27512][C-00000000] astobj2.c: bad magic number 0xb44b71d0 for object 0xb44b71cc [Feb 15 09:13:00] ERROR[27512][C-00000000] astobj2.c: bad magic number 0xb44b71d0 for object 0xb44b71cc [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Feb 15 09:13:00] DEBUG[27512][C-00000000] netsock2.c: Splitting '10.10.5.64:5060' into... [Feb 15 09:13:00] DEBUG[27512][C-00000000] netsock2.c: ...host '10.10.5.64' and port '5060'. [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP o=- 1360887948 1360887949 IN IP4 10.10.5.226... OK. [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED OR FAILED. [Feb 15 09:13:00] DEBUG[27512][C-00000000] netsock2.c: Splitting '10.10.5.226' into... [Feb 15 09:13:00] DEBUG[27512][C-00000000] netsock2.c: ...host '10.10.5.226' and port ''. [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP c=IN IP4 10.10.5.226... OK. [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: Processing session-level SDP a=sendonly... OK. [Feb 15 09:13:00] DEBUG[27512][C-00000000] rtp_engine.c: Setting payload 8 based on m type on 0xb4a53dac [Feb 15 09:13:00] DEBUG[27512][C-00000000] rtp_engine.c: Setting payload 101 based on m type on 0xb4a53dac [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=sendonly... OK. [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Feb 15 09:13:00] DEBUG[27512][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x89ba68c' [Feb 15 09:13:00] DEBUG[27512][C-00000000] rtp_engine.c: Copying payload 8 from 0xb4a53dac to 0x89ba838 [Feb 15 09:13:00] DEBUG[27512][C-00000000] rtp_engine.c: Copying payload 101 from 0xb4a53dac to 0x89ba838 [Feb 15 09:13:00] DEBUG[27512][C-00000000] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x89ba68c' [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: We're settling with these formats: (alaw) [Feb 15 09:13:00] DEBUG[27512][C-00000000] chan_sip.c: We have an owner, now see if we need to change this call