[Apr 8 16:02:47] Asterisk SVN-branch-12-r411945 built by root @ newtonr-laptop on a x86_64 running Linux on 2014-04-08 19:29:04 UTC [Apr 8 16:02:47] DEBUG[20135] config.c: Parsing /etc/asterisk/logger.conf [Apr 8 16:02:47] VERBOSE[20135] config.c: == Parsing '/etc/asterisk/logger.conf': Found [Apr 8 16:02:47] VERBOSE[20135] logger.c: Asterisk Queue Logger restarted [Apr 8 16:02:52] DEBUG[19931] chan_sip.c: = Looking for Call ID: 1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv (Checking From) --From tag FWJ0LyMfT9T6s6nmXo-k5Cm2z-V3PeiV --To-tag [Apr 8 16:02:52] DEBUG[19931] acl.c: For destination '10.24.18.16', our source address is '10.24.18.124'. [Apr 8 16:02:52] DEBUG[19931] chan_sip.c: Setting AST_TRANSPORT_UDP with address 10.24.18.124:5060 [Apr 8 16:02:52] DEBUG[19931] netsock2.c: Splitting '10.24.18.16:5060' into... [Apr 8 16:02:52] DEBUG[19931] netsock2.c: ...host '10.24.18.16' and port '5060'. [Apr 8 16:02:52] DEBUG[19931] chan_sip.c: Allocating new SIP dialog for 1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv - INVITE (No RTP) [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Apr 8 16:02:52] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces, 100rel, timer, norefersub" [Apr 8 16:02:52] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Found SIP option: -replaces- [Apr 8 16:02:52] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Matched SIP option: replaces [Apr 8 16:02:52] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Found SIP option: -100rel- [Apr 8 16:02:52] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Matched SIP option: 100rel [Apr 8 16:02:52] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Found SIP option: -timer- [Apr 8 16:02:52] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Matched SIP option: timer [Apr 8 16:02:52] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Found SIP option: -norefersub- [Apr 8 16:02:52] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Matched SIP option: norefersub [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.16:5060' into... [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.16' and port '5060'. [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.24.18.16:5060 [Apr 8 16:02:52] DEBUG[19931] chan_sip.c: = Looking for Call ID: 1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv (Checking From) --From tag FWJ0LyMfT9T6s6nmXo-k5Cm2z-V3PeiV --To-tag as56304e69 [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Stopping retransmission on '1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv' of Response 21974: Match Found [Apr 8 16:02:52] DEBUG[19931] chan_sip.c: = Looking for Call ID: 1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv (Checking From) --From tag FWJ0LyMfT9T6s6nmXo-k5Cm2z-V3PeiV --To-tag [Apr 8 16:02:52] DEBUG[19931] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:02:52] DEBUG[19931] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:02:52] DEBUG[19931] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:02:52] DEBUG[19931] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.16:5060' into... [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.16' and port '5060'. [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:02:52] DEBUG[19931][C-00000008] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f717002bb28' [Apr 8 16:02:52] DEBUG[19931][C-00000008] res_rtp_asterisk.c: Allocated port 19894 for RTP instance '0x7f717002bb28' [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:02:52] DEBUG[19931][C-00000008] rtp_engine.c: RTP instance '0x7f717002bb28' is setup and ready to go [Apr 8 16:02:52] DEBUG[19931][C-00000008] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f717002bb28' [Apr 8 16:02:52] VERBOSE[19931][C-00000008] netsock2.c: == Using SIP RTP CoS mark 5 [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Setting NAT on RTP to Off [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP o=- 92362262 92362262 IN IP4 10.24.18.16... OK. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP s=digphn... UNSUPPORTED OR FAILED. [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.16' into... [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.16' and port ''. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP c=IN IP4 10.24.18.16... OK. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP a=X-nat:0... UNSUPPORTED OR FAILED. [Apr 8 16:02:52] DEBUG[19931][C-00000008] rtp_engine.c: Setting payload 0 based on m type on 0x7f7147a9bf40 [Apr 8 16:02:52] DEBUG[19931][C-00000008] rtp_engine.c: Setting payload 8 based on m type on 0x7f7147a9bf40 [Apr 8 16:02:52] DEBUG[19931][C-00000008] rtp_engine.c: Setting payload 9 based on m type on 0x7f7147a9bf40 [Apr 8 16:02:52] DEBUG[19931][C-00000008] rtp_engine.c: Setting payload 96 based on m type on 0x7f7147a9bf40 [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtcp:4019 IN IP4 10.24.18.16... UNSUPPORTED OR FAILED. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:96 telephone-event/8000... OK. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=fmtp:96 0-15... UNSUPPORTED OR FAILED. [Apr 8 16:02:52] DEBUG[19931][C-00000008] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f717002bb28' [Apr 8 16:02:52] DEBUG[19931][C-00000008] rtp_engine.c: Copying payload 0 from 0x7f7147a9bf40 to 0x7f717002bc68 [Apr 8 16:02:52] DEBUG[19931][C-00000008] rtp_engine.c: Copying payload 8 from 0x7f7147a9bf40 to 0x7f717002bc68 [Apr 8 16:02:52] DEBUG[19931][C-00000008] rtp_engine.c: Copying payload 9 from 0x7f7147a9bf40 to 0x7f717002bc68 [Apr 8 16:02:52] DEBUG[19931][C-00000008] rtp_engine.c: Copying payload 96 from 0x7f7147a9bf40 to 0x7f717002bc68 [Apr 8 16:02:52] DEBUG[19931][C-00000008] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f717002bb28' [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: We're settling with these formats: (ulaw) [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Checking SIP call limits for device 6001 [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Updating call counter for incoming call [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:02:52] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Incoming INVITE with 'timer' option supported [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: INVITE also has "Session-Expires" header. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Session-Expires: 1800 [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: INVITE also has "Min-SE" header. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Received Min-SE: 90 [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: *** Our native formats are (ulaw) [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: *** Joint capabilities are (ulaw) [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: *** Our capabilities are (ulaw) [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: This channel will not be able to handle video. [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: build_route: Contact hop: "RustyONE" [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Session timer started: 677 - 1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv 900000ms [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: SIP/6001-00000018: New call is still down.... Trying... [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.24.18.16:5060 [Apr 8 16:02:52] DEBUG[19894] devicestate.c: No provider found, checking channel drivers for SIP - 6001 [Apr 8 16:02:52] DEBUG[19894] chan_sip.c: Checking device state for peer 6001 [Apr 8 16:02:52] DEBUG[19894] devicestate.c: Changing state for SIP/6001 - state 1 (Not in use) [Apr 8 16:02:52] DEBUG[20174][C-00000008] pbx.c: Launching 'AGI' [Apr 8 16:02:52] VERBOSE[20174][C-00000008] pbx.c: -- Executing [1@agi-test-context:1] AGI("SIP/6001-00000018", "/root/asterisk.sh") in new stack [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: -- Launched AGI Script /root/asterisk.sh [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_request: /root/asterisk.sh [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_channel: SIP/6001-00000018 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_language: en [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_type: SIP [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_uniqueid: 1396990972.40 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_version: SVN-branch-12-r411945 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_callerid: 6001 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_calleridname: Alice [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_callingpres: 0 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_callingani2: 0 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_callington: 0 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_callingtns: 0 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_dnid: 1 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_rdnis: unknown [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_context: agi-test-context [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_extension: 1 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_priority: 1 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_enhanced: 0.0 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_accountcode: [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> agi_threadid: 140124501767936 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Rx << ANSWER [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: SIP answering channel: SIP/6001-00000018 [Apr 8 16:02:52] DEBUG[19894] devicestate.c: No provider found, checking channel drivers for SIP - 6001 [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Setting the marker bit due to a source update [Apr 8 16:02:52] DEBUG[19894] chan_sip.c: Checking device state for peer 6001 [Apr 8 16:02:52] DEBUG[19894] devicestate.c: Changing state for SIP/6001 - state 1 (Not in use) [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Setting framing from config on incoming call [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: ** Our capability: (ulaw) Video flag: True Text flag: True [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: ** Our prefcodec: (nothing) [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: -- Done with adding codecs to SDP [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Done building SDP. Settling with this capability: (ulaw) [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.24.18.16:5060 [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: 0x7f7170001750 -- Probation learning mode pass with source address 10.24.18.16:4018 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_rtp_asterisk.c: > 0x7f7170001750 -- Probation passed - setting RTP source address to 10.24.18.16:4018 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> 200 result=0 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: AGI Rx << EXEC Dial SIP/6004 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] res_agi.c: -- AGI Script Executing Application: (Dial) Options: (SIP/6004) [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Asked to create a SIP channel with formats: (ulaw) [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Allocating new SIP dialog for 4217f2892939683d4facdcfe2384fa42@127.0.1.1:5060 - INVITE (No RTP) [Apr 8 16:02:52] DEBUG[20174][C-00000008] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f71d4009a18' [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Allocated port 11812 for RTP instance '0x7f71d4009a18' [Apr 8 16:02:52] DEBUG[20174][C-00000008] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:02:52] DEBUG[20174][C-00000008] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:02:52] DEBUG[20174][C-00000008] rtp_engine.c: RTP instance '0x7f71d4009a18' is setup and ready to go [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f71d4009a18' [Apr 8 16:02:52] VERBOSE[20174][C-00000008] netsock2.c: == Using SIP RTP CoS mark 5 [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Setting NAT on RTP to Off [Apr 8 16:02:52] DEBUG[20174][C-00000008] acl.c: For destination '10.24.18.166', our source address is '10.24.18.124'. [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Setting AST_TRANSPORT_UDP with address 10.24.18.124:5060 [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Setting NAT on RTP to Off [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: SIP call-id changed from '4217f2892939683d4facdcfe2384fa42@127.0.1.1:5060' to '0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060' [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: *** Our native formats are (ulaw) [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: *** Joint capabilities are (ulaw) [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: *** Our capabilities are (ulaw) [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: *** Our preferred formats from the incoming channel are (ulaw) [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: This channel will not be able to handle video. [Apr 8 16:02:52] DEBUG[20174][C-00000008] channel_internal_api.c: Channel Call ID changing from [C-00000008] to [C-00000008] [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Outgoing Call for 6004 [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Updating call counter for outgoing call [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: ** Our capability: (ulaw) Video flag: False Text flag: False [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: ** Our prefcodec: (ulaw) [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: -- Done with adding codecs to SDP [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Done building SDP. Settling with this capability: (ulaw) [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Initializing initreq for method INVITE - callid 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 [Apr 8 16:02:52] DEBUG[20174][C-00000008] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.24.18.166:5060 [Apr 8 16:02:52] VERBOSE[20174][C-00000008] app_dial.c: -- Called SIP/6004 [Apr 8 16:02:52] DEBUG[20174][C-00000008] channel.c: SIP/6001-00000018: Dropping redundant connected line update "David" <6004>. [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[19931] chan_sip.c: = Looking for Call ID: 1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv (Checking From) --From tag FWJ0LyMfT9T6s6nmXo-k5Cm2z-V3PeiV --To-tag as33ca3798 [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: Stopping retransmission on '1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv' of Response 21975: Match Found [Apr 8 16:02:52] DEBUG[19931] chan_sip.c: = Looking for Call ID: 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 (Checking To) --From tag as48d1adf0 --To-tag [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060' Request 102: Found [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: SIP response 100 to standard invite [Apr 8 16:02:52] DEBUG[19931] chan_sip.c: = Looking for Call ID: 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 (Checking To) --From tag as48d1adf0 --To-tag 1941216194 [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060' Request 102: Found [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: SIP response 180 to standard invite [Apr 8 16:02:52] DEBUG[19931][C-00000008] chan_sip.c: build_route: Contact hop: [Apr 8 16:02:52] DEBUG[19894] devicestate.c: No provider found, checking channel drivers for SIP - 6004 [Apr 8 16:02:52] DEBUG[19894] chan_sip.c: Checking device state for peer 6004 [Apr 8 16:02:52] DEBUG[19894] devicestate.c: Changing state for SIP/6004 - state 1 (Not in use) [Apr 8 16:02:52] VERBOSE[20174][C-00000008] app_dial.c: -- SIP/6004-00000019 is ringing [Apr 8 16:02:52] DEBUG[20174][C-00000008] rtp_engine.c: Setting early bridge SDP of 'SIP/6001-00000018' with that of 'SIP/6004-00000019' [Apr 8 16:02:52] DEBUG[20174][C-00000008] channel.c: Driver for channel 'SIP/6001-00000018' does not support indication 3, emulating it [Apr 8 16:02:52] DEBUG[20174][C-00000008] channel.c: Set channel SIP/6001-00000018 to write format slin [Apr 8 16:02:52] DEBUG[20174][C-00000008] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:52] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:53] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:54] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:55] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d4009a18' so dropping frame [Apr 8 16:02:56] DEBUG[19931] chan_sip.c: = Looking for Call ID: 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 (Checking To) --From tag as48d1adf0 --To-tag 1941216194 [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Acked pending invite 102 [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Stopping retransmission on '0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060' of Request 102: Match Found [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: SIP response 200 to standard invite [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP o=6004 67719419 11740294 IN IP4 10.24.18.166... OK. [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP s=A conversation... UNSUPPORTED OR FAILED. [Apr 8 16:02:56] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.166' into... [Apr 8 16:02:56] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.166' and port ''. [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP c=IN IP4 10.24.18.166... OK. [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Apr 8 16:02:56] DEBUG[19931][C-00000008] rtp_engine.c: Setting payload 0 based on m type on 0x7f7147a9bdc0 [Apr 8 16:02:56] DEBUG[19931][C-00000008] rtp_engine.c: Setting payload 101 based on m type on 0x7f7147a9bdc0 [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Apr 8 16:02:56] DEBUG[19931][C-00000008] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f71d4009a18' [Apr 8 16:02:56] DEBUG[19931][C-00000008] rtp_engine.c: Copying payload 0 from 0x7f7147a9bdc0 to 0x7f71d4009b58 [Apr 8 16:02:56] DEBUG[19931][C-00000008] rtp_engine.c: Copying payload 101 from 0x7f7147a9bdc0 to 0x7f71d4009b58 [Apr 8 16:02:56] DEBUG[19931][C-00000008] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f71d4009a18' [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: We're settling with these formats: (ulaw) [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: We have an owner, now see if we need to change this call [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Updating call counter for outgoing call [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: build_route: Contact hop: [Apr 8 16:02:56] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.166:5060' into... [Apr 8 16:02:56] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.166' and port '5060'. [Apr 8 16:02:56] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.166:5060' into... [Apr 8 16:02:56] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.166' and port '5060'. [Apr 8 16:02:56] DEBUG[19931][C-00000008] chan_sip.c: Trying to put 'ACK sip:600' onto UDP socket destined for 10.24.18.166:5060 [Apr 8 16:02:56] DEBUG[20174][C-00000008] channel.c: SIP/6001-00000018: Dropping redundant connected line update "David" <6004>. [Apr 8 16:02:56] VERBOSE[20174][C-00000008] app_dial.c: -- SIP/6004-00000019 answered SIP/6001-00000018 [Apr 8 16:02:56] DEBUG[19894] devicestate.c: No provider found, checking channel drivers for SIP - 6004 [Apr 8 16:02:56] DEBUG[19894] chan_sip.c: Checking device state for peer 6004 [Apr 8 16:02:56] DEBUG[20174][C-00000008] rtp_engine.c: Setting early bridge SDP of 'SIP/6001-00000018' with that of 'SIP/6004-00000019' [Apr 8 16:02:56] DEBUG[19894] devicestate.c: Changing state for SIP/6004 - state 1 (Not in use) [Apr 8 16:02:56] DEBUG[20174][C-00000008] channel.c: Set channel SIP/6001-00000018 to write format ulaw [Apr 8 16:02:56] DEBUG[20174][C-00000008] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 8 16:02:56] DEBUG[20174][C-00000008] features.c: Removing dialed interfaces datastore on SIP/6004-00000019 since we're bridging [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge_native_rtp.c: Bridge 'e0cac3f7-6699-4885-a5b3-6975e1fb40b8' can not use native RTP bridge as two channels are required [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Chose bridge technology simple_bridge [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: calling simple_bridge technology constructor [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: calling simple_bridge technology start [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge_channel.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: 0x7f71d4012758(SIP/6001-00000018) is joining [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge_channel.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: 0x7f71d4030748(SIP/6004-00000019) is joining [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge_channel.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: pushing 0x7f71d4012758(SIP/6001-00000018) [Apr 8 16:02:56] VERBOSE[20174][C-00000008] bridge_channel.c: -- Channel SIP/6001-00000018 joined 'simple_bridge' basic-bridge [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge_native_rtp.c: Bridge 'e0cac3f7-6699-4885-a5b3-6975e1fb40b8' can not use native RTP bridge as two channels are required [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want. [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Chose bridge technology simple_bridge [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8 is already using the new technology. [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8 is happy that channel SIP/6001-00000018 already has read format ulaw [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8 is happy that channel SIP/6001-00000018 already has write format ulaw [Apr 8 16:02:56] DEBUG[20174][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: 0x7f71d4012758(SIP/6001-00000018) is joining simple_bridge technology [Apr 8 16:02:56] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Changing ssrc from 1145249809 to 400764623 due to a source change [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge_channel.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: pushing 0x7f71d4030748(SIP/6004-00000019) [Apr 8 16:02:56] VERBOSE[20176][C-00000008] bridge_channel.c: -- Channel SIP/6004-00000019 joined 'simple_bridge' basic-bridge [Apr 8 16:02:56] DEBUG[19896] cdr.c: Finalized CDR for SIP/6004-00000019 - start 1396990972.631916 answer 1396990976.872389 end 1396990976.874186 dispo ANSWERED [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want. [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Chose bridge technology native_rtp [Apr 8 16:02:56] VERBOSE[20176][C-00000008] bridge.c: > Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: switching from simple_bridge technology to native_rtp [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: calling native_rtp technology constructor [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: calling simple_bridge technology stop [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: 0x7f71d4012758(SIP/6001-00000018) is leaving simple_bridge technology (dummy) [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8 is happy that channel SIP/6001-00000018 already has read format ulaw [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8 is happy that channel SIP/6001-00000018 already has write format ulaw [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: 0x7f71d4012758(SIP/6001-00000018) is joining native_rtp technology [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge_native_rtp.c: Locally RTP bridged 'SIP/6001-00000018' and 'SIP/6004-00000019' in stack [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8 is happy that channel SIP/6004-00000019 already has read format ulaw [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8 is happy that channel SIP/6004-00000019 already has write format ulaw [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: 0x7f71d4030748(SIP/6004-00000019) is joining native_rtp technology [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge_native_rtp.c: Locally RTP bridged 'SIP/6001-00000018' and 'SIP/6004-00000019' in stack [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: calling native_rtp technology start [Apr 8 16:02:56] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: calling simple_bridge technology destructor [Apr 8 16:02:56] DEBUG[20176][C-00000008] res_rtp_asterisk.c: Not changing SSRC since we haven't sent any RTP yet [Apr 8 16:02:57] DEBUG[20176][C-00000008] res_rtp_asterisk.c: 0x7f71d4013b60 -- Probation learning mode pass with source address 10.24.18.166:10018 [Apr 8 16:02:57] VERBOSE[20176][C-00000008] res_rtp_asterisk.c: > 0x7f71d4013b60 -- Probation passed - setting RTP source address to 10.24.18.166:10018 [Apr 8 16:02:58] DEBUG[20176][C-00000008] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Apr 8 16:02:59] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Apr 8 16:03:00] DEBUG[19931] chan_sip.c: = Looking for Call ID: 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 (Checking From) --From tag 1941216194 --To-tag as48d1adf0 [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Apr 8 16:03:00] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces, join, path" [Apr 8 16:03:00] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Found SIP option: -replaces- [Apr 8 16:03:00] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Matched SIP option: replaces [Apr 8 16:03:00] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Found SIP option: -join- [Apr 8 16:03:00] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Matched SIP option: join [Apr 8 16:03:00] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Found SIP option: -path- [Apr 8 16:03:00] DEBUG[19931][C-00000008] sip/reqresp_parser.c: Matched SIP option: path [Apr 8 16:03:00] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.166:5060' into... [Apr 8 16:03:00] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.166' and port '5060'. [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: Call 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 responded to our reinvite without changing SDP version; ignoring SDP. [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: SIP/6004-00000019: This call is UP.... [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.24.18.166:5060 [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: Setting framing from config on incoming call [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: ** Our capability: (ulaw) Video flag: True Text flag: True [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: ** Our prefcodec: (ulaw) [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: -- Done with adding codecs to SDP [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: Done building SDP. Settling with this capability: (ulaw) [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.24.18.166:5060 [Apr 8 16:03:00] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Setting the marker bit due to a source update [Apr 8 16:03:00] DEBUG[20174][C-00000008] bridge_native_rtp.c: Locally RTP bridged 'SIP/6001-00000018' and 'SIP/6004-00000019' in stack [Apr 8 16:03:00] DEBUG[19931] chan_sip.c: = Looking for Call ID: 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 (Checking From) --From tag 1941216194 --To-tag as48d1adf0 [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Apr 8 16:03:00] DEBUG[19931][C-00000008] chan_sip.c: Stopping retransmission on '0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060' of Response 1: Match Found [Apr 8 16:03:04] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Apr 8 16:03:06] DEBUG[19931] chan_sip.c: = Looking for Call ID: 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 (Checking From) --From tag 1941216194 --To-tag as48d1adf0 [Apr 8 16:03:06] DEBUG[19931][C-00000008] chan_sip.c: **** Received REFER (9) - Command in SIP REFER [Apr 8 16:03:06] DEBUG[19931][C-00000008] chan_sip.c: Trying to put 'SIP/2.0 202' onto UDP socket destined for 10.24.18.166:5060 [Apr 8 16:03:06] DEBUG[20174][C-00000008] bridge_native_rtp.c: Locally RTP bridged 'SIP/6001-00000018' and 'SIP/6004-00000019' in stack [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Setting the marker bit due to a source update [Apr 8 16:03:06] DEBUG[19931][C-00000008] parking/parking_bridge_features.c: Checking if 12@agi-test-context is a parking exten [Apr 8 16:03:06] DEBUG[19931][C-00000008] bridge_channel.c: Setting 0x7f71d4030748(SIP/6004-00000019) state from:0 to:2 [Apr 8 16:03:06] DEBUG[20174][C-00000008] channel.c: Soft-Hanging up channel 'SIP/6001-00000018' [Apr 8 16:03:06] DEBUG[20174][C-00000008] bridge_channel.c: Setting 0x7f71d4012758(SIP/6001-00000018) state from:0 to:1 [Apr 8 16:03:06] DEBUG[20174][C-00000008] bridge_channel.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: pulling 0x7f71d4012758(SIP/6001-00000018) [Apr 8 16:03:06] VERBOSE[20174][C-00000008] bridge_channel.c: -- Channel SIP/6001-00000018 left 'native_rtp' basic-bridge [Apr 8 16:03:06] DEBUG[20174][C-00000008] bridge_channel.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: 0x7f71d4012758(SIP/6001-00000018) is leaving native_rtp technology [Apr 8 16:03:06] DEBUG[20174][C-00000008] bridge_native_rtp.c: Discontinued RTP bridging of 'SIP/6001-00000018' and 'SIP/6004-00000019' - media will flow through Asterisk core [Apr 8 16:03:06] DEBUG[20174][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: dissolving bridge with cause 16(Normal Clearing) [Apr 8 16:03:06] DEBUG[20174][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: queueing action type:13 sub:1001 [Apr 8 16:03:06] DEBUG[20174][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8 is dissolved, not performing smart bridge operation. [Apr 8 16:03:06] DEBUG[19896] cdr.c: Finalized CDR for SIP/6001-00000018 - start 1396990972.378974 answer 1396990972.389949 end 1396990986.489252 dispo ANSWERED [Apr 8 16:03:06] DEBUG[20176][C-00000008] bridge_channel.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: pulling 0x7f71d4030748(SIP/6004-00000019) [Apr 8 16:03:06] VERBOSE[20176][C-00000008] bridge_channel.c: -- Channel SIP/6004-00000019 left 'native_rtp' basic-bridge [Apr 8 16:03:06] DEBUG[20176][C-00000008] bridge_channel.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: 0x7f71d4030748(SIP/6004-00000019) is leaving native_rtp technology [Apr 8 16:03:06] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.166:5060' into... [Apr 8 16:03:06] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.166' and port '5060'. [Apr 8 16:03:06] DEBUG[19931][C-00000008] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 10.24.18.166:5060 [Apr 8 16:03:06] DEBUG[20174][C-00000008] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Apr 8 16:03:06] VERBOSE[20174][C-00000008] res_agi.c: AGI Tx >> 200 result=0 [Apr 8 16:03:06] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8 is dissolved, not performing smart bridge operation. [Apr 8 16:03:06] DEBUG[20176][C-00000008] res_rtp_asterisk.c: Not changing SSRC since we haven't sent any RTP yet [Apr 8 16:03:06] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: actually destroying basic bridge, nobody wants it anymore [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_agi.c: SIP/6001-00000018 hungup [Apr 8 16:03:06] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: calling basic bridge destructor [Apr 8 16:03:06] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: calling native_rtp technology stop [Apr 8 16:03:06] DEBUG[20176][C-00000008] bridge.c: Bridge e0cac3f7-6699-4885-a5b3-6975e1fb40b8: calling native_rtp technology destructor [Apr 8 16:03:06] DEBUG[20176][C-00000008] channel.c: Hanging up channel 'SIP/6004-00000019' [Apr 8 16:03:06] DEBUG[20176][C-00000008] chan_sip.c: SIP Transfer: Not hanging up right now... Rescheduling hangup for 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060. [Apr 8 16:03:06] VERBOSE[20174][C-00000008] res_agi.c: -- AGI Script /root/asterisk.sh completed, returning 4 [Apr 8 16:03:06] DEBUG[19896] cdr.c: CDR for SIP/6004-00000019 is dialed and has no Party B; discarding [Apr 8 16:03:06] DEBUG[19894] devicestate.c: No provider found, checking channel drivers for SIP - 6004 [Apr 8 16:03:06] DEBUG[19894] chan_sip.c: Checking device state for peer 6004 [Apr 8 16:03:06] DEBUG[19894] devicestate.c: Changing state for SIP/6004 - state 1 (Not in use) [Apr 8 16:03:06] DEBUG[20174][C-00000008] pbx.c: Spawn extension (agi-test-context,12,1) exited non-zero on 'SIP/6001-00000018' [Apr 8 16:03:06] VERBOSE[20174][C-00000008] pbx.c: == Spawn extension (agi-test-context, 12, 1) exited non-zero on 'SIP/6001-00000018' [Apr 8 16:03:06] DEBUG[20174][C-00000008] pbx.c: Launching 'Dial' [Apr 8 16:03:06] VERBOSE[20174][C-00000008] pbx.c: -- Executing [12@agi-test-context:1] Dial("SIP/6001-00000018", "SIP/6002,45,Tt") in new stack [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: Asked to create a SIP channel with formats: (ulaw) [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: Allocating new SIP dialog for 1f370ca63fffc83300842dd44eea4dc1@127.0.1.1:5060 - INVITE (No RTP) [Apr 8 16:03:06] DEBUG[20174][C-00000008] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f71d401bc88' [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Allocated port 12162 for RTP instance '0x7f71d401bc88' [Apr 8 16:03:06] DEBUG[20174][C-00000008] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:03:06] DEBUG[20174][C-00000008] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:03:06] DEBUG[20174][C-00000008] rtp_engine.c: RTP instance '0x7f71d401bc88' is setup and ready to go [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f71d401bc88' [Apr 8 16:03:06] VERBOSE[20174][C-00000008] netsock2.c: == Using SIP RTP CoS mark 5 [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: Setting NAT on RTP to Off [Apr 8 16:03:06] DEBUG[20174][C-00000008] acl.c: For destination '10.24.18.138', our source address is '10.24.18.124'. [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: Setting AST_TRANSPORT_UDP with address 10.24.18.124:5060 [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: Setting NAT on RTP to Off [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: SIP call-id changed from '1f370ca63fffc83300842dd44eea4dc1@127.0.1.1:5060' to '160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060' [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: *** Our native formats are (ulaw) [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: *** Joint capabilities are (ulaw) [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: *** Our capabilities are (ulaw) [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: *** Our preferred formats from the incoming channel are (ulaw) [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: This channel will not be able to handle video. [Apr 8 16:03:06] DEBUG[20174][C-00000008] channel_internal_api.c: Channel Call ID changing from [C-00000008] to [C-00000008] [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: Outgoing Call for 6002 [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: Updating call counter for outgoing call [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: ** Our capability: (ulaw) Video flag: False Text flag: False [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: ** Our prefcodec: (ulaw) [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: -- Done with adding codecs to SDP [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: Done building SDP. Settling with this capability: (ulaw) [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: Initializing initreq for method INVITE - callid 160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060 [Apr 8 16:03:06] DEBUG[20174][C-00000008] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.24.18.138:5060 [Apr 8 16:03:06] VERBOSE[20174][C-00000008] app_dial.c: -- Called SIP/6002 [Apr 8 16:03:06] DEBUG[20174][C-00000008] channel.c: SIP/6001-00000018: Dropping redundant connected line update "Bob" <6002>. [Apr 8 16:03:06] DEBUG[19931] chan_sip.c: = Looking for Call ID: 160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060 (Checking To) --From tag as23693ef2 --To-tag [Apr 8 16:03:06] DEBUG[19931][C-00000008] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060' Request 102: Found [Apr 8 16:03:06] DEBUG[19931][C-00000008] chan_sip.c: SIP response 100 to standard invite [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[19931] chan_sip.c: = Looking for Call ID: 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 (Checking To) --From tag as48d1adf0 --To-tag 1941216194 [Apr 8 16:03:06] DEBUG[19931][C-00000008] chan_sip.c: Stopping retransmission on '0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060' of Request 103: Match Found [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[19931] chan_sip.c: = Looking for Call ID: 160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060 (Checking To) --From tag as23693ef2 --To-tag mLy8R5dLH38gw0LFeZTRFu16.YasQbAv [Apr 8 16:03:06] DEBUG[19931][C-00000008] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060' Request 102: Found [Apr 8 16:03:06] DEBUG[19931][C-00000008] chan_sip.c: SIP response 180 to standard invite [Apr 8 16:03:06] DEBUG[19931][C-00000008] chan_sip.c: build_route: Contact hop: "RustyTWO" [Apr 8 16:03:06] DEBUG[19894] devicestate.c: No provider found, checking channel drivers for SIP - 6002 [Apr 8 16:03:06] DEBUG[19894] chan_sip.c: Checking device state for peer 6002 [Apr 8 16:03:06] DEBUG[19894] devicestate.c: Changing state for SIP/6002 - state 1 (Not in use) [Apr 8 16:03:06] VERBOSE[20174][C-00000008] app_dial.c: -- SIP/6002-0000001a is ringing [Apr 8 16:03:06] DEBUG[20174][C-00000008] rtp_engine.c: Setting early bridge SDP of 'SIP/6001-00000018' with that of 'SIP/6002-0000001a' [Apr 8 16:03:06] DEBUG[20174][C-00000008] channel.c: Driver for channel 'SIP/6001-00000018' does not support indication 3, emulating it [Apr 8 16:03:06] DEBUG[20174][C-00000008] channel.c: Set channel SIP/6001-00000018 to write format slin [Apr 8 16:03:06] DEBUG[20174][C-00000008] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Difference is 77688, ms is 9731 [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:06] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[19931] chan_sip.c: = Looking for Call ID: 8323200811233-281921055718516@10.24.18.166 (Checking From) --From tag 90986116 --To-tag [Apr 8 16:03:07] DEBUG[19931] acl.c: For destination '10.24.18.166', our source address is '10.24.18.124'. [Apr 8 16:03:07] DEBUG[19931] chan_sip.c: Setting AST_TRANSPORT_UDP with address 10.24.18.124:5060 [Apr 8 16:03:07] DEBUG[19931] netsock2.c: Splitting '10.24.18.166:5060' into... [Apr 8 16:03:07] DEBUG[19931] netsock2.c: ...host '10.24.18.166' and port '5060'. [Apr 8 16:03:07] DEBUG[19931] chan_sip.c: Allocating new SIP dialog for 8323200811233-281921055718516@10.24.18.166 - REGISTER (No RTP) [Apr 8 16:03:07] DEBUG[19931] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Apr 8 16:03:07] DEBUG[19931] netsock2.c: Splitting '10.24.18.166:5060' into... [Apr 8 16:03:07] DEBUG[19931] netsock2.c: ...host '10.24.18.166' and port '5060'. [Apr 8 16:03:07] DEBUG[19931] netsock2.c: Splitting '10.24.18.124:5060' into... [Apr 8 16:03:07] DEBUG[19931] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:03:07] DEBUG[19931] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.24.18.166:5060 [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[19931] chan_sip.c: = Looking for Call ID: 8323200811233-281921055718516@10.24.18.166 (Checking From) --From tag 90986116 --To-tag [Apr 8 16:03:07] DEBUG[19931] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:03:07] DEBUG[19931] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:03:07] DEBUG[19931] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:03:07] DEBUG[19931] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:03:07] DEBUG[19931] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Apr 8 16:03:07] DEBUG[19931] netsock2.c: Splitting '10.24.18.166:5060' into... [Apr 8 16:03:07] DEBUG[19931] netsock2.c: ...host '10.24.18.166' and port '5060'. [Apr 8 16:03:07] DEBUG[19931] netsock2.c: Splitting '10.24.18.124:5060' into... [Apr 8 16:03:07] DEBUG[19931] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:03:07] DEBUG[19931] chan_sip.c: Store REGISTER's Contact header for call routing. [Apr 8 16:03:07] DEBUG[19931] netsock2.c: Splitting '10.24.18.166:5060' into... [Apr 8 16:03:07] DEBUG[19931] netsock2.c: ...host '10.24.18.166' and port '5060'. [Apr 8 16:03:07] DEBUG[19931] chan_sip.c: build_path: do not use Path headers [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[19931] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.24.18.166:5060 [Apr 8 16:03:07] DEBUG[19894] devicestate.c: No provider found, checking channel drivers for SIP - 6004 [Apr 8 16:03:07] DEBUG[19894] chan_sip.c: Checking device state for peer 6004 [Apr 8 16:03:07] DEBUG[19894] devicestate.c: Changing state for SIP/6004 - state 1 (Not in use) [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:07] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[19931] chan_sip.c: = Looking for Call ID: 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 (Checking From) --From tag 1941216194 --To-tag as48d1adf0 [Apr 8 16:03:08] DEBUG[19931][C-00000008] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Apr 8 16:03:08] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.166:5060' into... [Apr 8 16:03:08] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.166' and port '5060'. [Apr 8 16:03:08] DEBUG[19931][C-00000008] chan_sip.c: Setting SIP_ALREADYGONE on dialog 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 [Apr 8 16:03:08] DEBUG[19931][C-00000008] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f71d4009a18' [Apr 8 16:03:08] DEBUG[19931][C-00000008] chan_sip.c: Received bye, no owner, selfdestruct soon. [Apr 8 16:03:08] DEBUG[19931][C-00000008] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.24.18.166:5060 [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:08] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[19931] chan_sip.c: Auto destroying SIP dialog '-.I72cbVlmiEx1OpKvsfriYoN22tzTFh' [Apr 8 16:03:09] DEBUG[19931] chan_sip.c: Destroying SIP dialog -.I72cbVlmiEx1OpKvsfriYoN22tzTFh [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:09] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: 0x7f71d402e4b0 -- Probation learning mode pass with source address 10.24.18.138:4016 [Apr 8 16:03:10] VERBOSE[20174][C-00000008] res_rtp_asterisk.c: > 0x7f71d402e4b0 -- Probation passed - setting RTP source address to 10.24.18.138:4016 [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: No remote address on RTP instance '0x7f71d401bc88' so dropping frame [Apr 8 16:03:10] DEBUG[19931] chan_sip.c: = Looking for Call ID: 160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060 (Checking To) --From tag as23693ef2 --To-tag mLy8R5dLH38gw0LFeZTRFu16.YasQbAv [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Acked pending invite 102 [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Stopping retransmission on '160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060' of Request 102: Match Found [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: SIP response 200 to standard invite [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP o=- 92362276 92362277 IN IP4 10.24.18.138... OK. [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP s=digphn... UNSUPPORTED OR FAILED. [Apr 8 16:03:10] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.138' into... [Apr 8 16:03:10] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.138' and port ''. [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP c=IN IP4 10.24.18.138... OK. [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Processing session-level SDP a=X-nat:0... UNSUPPORTED OR FAILED. [Apr 8 16:03:10] DEBUG[19931][C-00000008] rtp_engine.c: Setting payload 0 based on m type on 0x7f7147a9bdc0 [Apr 8 16:03:10] DEBUG[19931][C-00000008] rtp_engine.c: Setting payload 96 based on m type on 0x7f7147a9bdc0 [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtcp:4017 IN IP4 10.24.18.138... UNSUPPORTED OR FAILED. [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:96 telephone-event/8000... OK. [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=fmtp:96 0-15... UNSUPPORTED OR FAILED. [Apr 8 16:03:10] DEBUG[19931][C-00000008] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f71d401bc88' [Apr 8 16:03:10] DEBUG[19931][C-00000008] rtp_engine.c: Copying payload 0 from 0x7f7147a9bdc0 to 0x7f71d401bdc8 [Apr 8 16:03:10] DEBUG[19931][C-00000008] rtp_engine.c: Copying payload 96 from 0x7f7147a9bdc0 to 0x7f71d401bdc8 [Apr 8 16:03:10] DEBUG[19931][C-00000008] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f71d401bc88' [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: We're settling with these formats: (ulaw) [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: We have an owner, now see if we need to change this call [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Updating call counter for outgoing call [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: build_route: Contact hop: "RustyTWO" [Apr 8 16:03:10] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.138:5060' into... [Apr 8 16:03:10] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.138' and port '5060'. [Apr 8 16:03:10] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.138:5060' into... [Apr 8 16:03:10] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.138' and port '5060'. [Apr 8 16:03:10] DEBUG[19931][C-00000008] chan_sip.c: Trying to put 'ACK sip:600' onto UDP socket destined for 10.24.18.138:5060 [Apr 8 16:03:10] DEBUG[20174][C-00000008] channel.c: SIP/6001-00000018: Dropping redundant connected line update "Bob" <6002>. [Apr 8 16:03:10] DEBUG[19894] devicestate.c: No provider found, checking channel drivers for SIP - 6002 [Apr 8 16:03:10] DEBUG[19894] chan_sip.c: Checking device state for peer 6002 [Apr 8 16:03:10] DEBUG[19894] devicestate.c: Changing state for SIP/6002 - state 1 (Not in use) [Apr 8 16:03:10] VERBOSE[20174][C-00000008] app_dial.c: -- SIP/6002-0000001a answered SIP/6001-00000018 [Apr 8 16:03:10] DEBUG[20174][C-00000008] channel.c: Set channel SIP/6001-00000018 to write format ulaw [Apr 8 16:03:10] DEBUG[20174][C-00000008] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 8 16:03:10] DEBUG[20174][C-00000008] features.c: Removing dialed interfaces datastore on SIP/6002-0000001a since we're bridging [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge_native_rtp.c: Bridge '2a99ac40-e5f3-4fff-a7c3-05e358e1fe42' can not use native RTP bridge as two channels are required [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Chose bridge technology simple_bridge [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: calling simple_bridge technology constructor [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: calling simple_bridge technology start [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge_channel.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: 0x7f71d402c548(SIP/6001-00000018) is joining [Apr 8 16:03:10] DEBUG[20177][C-00000008] bridge_channel.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: 0x7f71d403c6e8(SIP/6002-0000001a) is joining [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge_channel.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: pushing 0x7f71d402c548(SIP/6001-00000018) [Apr 8 16:03:10] VERBOSE[20174][C-00000008] bridge_channel.c: -- Channel SIP/6001-00000018 joined 'simple_bridge' basic-bridge <2a99ac40-e5f3-4fff-a7c3-05e358e1fe42> [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge_native_rtp.c: Bridge '2a99ac40-e5f3-4fff-a7c3-05e358e1fe42' can not use native RTP bridge as two channels are required [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want. [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Chose bridge technology simple_bridge [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42 is already using the new technology. [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42 is happy that channel SIP/6001-00000018 already has read format ulaw [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42 is happy that channel SIP/6001-00000018 already has write format ulaw [Apr 8 16:03:10] DEBUG[20174][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: 0x7f71d402c548(SIP/6001-00000018) is joining simple_bridge technology [Apr 8 16:03:10] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Changing ssrc from 400764623 to 63844544 due to a source change [Apr 8 16:03:10] DEBUG[20177][C-00000008] bridge_channel.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: pushing 0x7f71d403c6e8(SIP/6002-0000001a) [Apr 8 16:03:10] VERBOSE[20177][C-00000008] bridge_channel.c: -- Channel SIP/6002-0000001a joined 'simple_bridge' basic-bridge <2a99ac40-e5f3-4fff-a7c3-05e358e1fe42> [Apr 8 16:03:10] DEBUG[19896] cdr.c: Finalized CDR for SIP/6002-0000001a - start 1396990986.492354 answer 1396990990.607767 end 1396990990.609945 dispo ANSWERED [Apr 8 16:03:10] DEBUG[20177][C-00000008] bridge_native_rtp.c: Bridge '2a99ac40-e5f3-4fff-a7c3-05e358e1fe42' can not use native RTP bridge as channel 'SIP/6001-00000018' has DTMF hooks [Apr 8 16:03:10] DEBUG[20177][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Apr 8 16:03:10] DEBUG[20177][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Apr 8 16:03:10] DEBUG[20177][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want. [Apr 8 16:03:10] DEBUG[20177][C-00000008] bridge.c: Chose bridge technology simple_bridge [Apr 8 16:03:10] DEBUG[20177][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42 is already using the new technology. [Apr 8 16:03:10] DEBUG[20177][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42 is happy that channel SIP/6002-0000001a already has read format ulaw [Apr 8 16:03:10] DEBUG[20177][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42 is happy that channel SIP/6002-0000001a already has write format ulaw [Apr 8 16:03:10] DEBUG[20177][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: 0x7f71d403c6e8(SIP/6002-0000001a) is joining simple_bridge technology [Apr 8 16:03:10] DEBUG[20177][C-00000008] res_rtp_asterisk.c: Not changing SSRC since we haven't sent any RTP yet [Apr 8 16:03:10] DEBUG[20177][C-00000008] res_rtp_asterisk.c: 0x7f71d402e4b0 -- Probation learning mode pass with source address 10.24.18.138:4016 [Apr 8 16:03:10] VERBOSE[20177][C-00000008] res_rtp_asterisk.c: > 0x7f71d402e4b0 -- Probation passed - setting RTP source address to 10.24.18.138:4016 [Apr 8 16:03:10] DEBUG[20177][C-00000008] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [Apr 8 16:03:10] DEBUG[20177][C-00000008] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [Apr 8 16:03:10] DEBUG[19931] chan_sip.c: Auto destroying SIP dialog 'Em8FIgh3R86-L7nayIfS7hE5KR8vfQpI' [Apr 8 16:03:10] DEBUG[19931] chan_sip.c: Destroying SIP dialog Em8FIgh3R86-L7nayIfS7hE5KR8vfQpI [Apr 8 16:03:14] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Apr 8 16:03:14] DEBUG[20177][C-00000008] res_rtp_asterisk.c: Got RTCP report of 64 bytes [Apr 8 16:03:14] DEBUG[19931] chan_sip.c: = Looking for Call ID: ca42de37-be0cae30-b2af0dd9@10.24.18.180 (Checking From) --From tag 7C9D6AA-C2FE3733 --To-tag [Apr 8 16:03:14] DEBUG[19931] acl.c: For destination '10.24.18.180', our source address is '10.24.18.124'. [Apr 8 16:03:14] DEBUG[19931] chan_sip.c: Setting AST_TRANSPORT_UDP with address 10.24.18.124:5060 [Apr 8 16:03:14] DEBUG[19931] netsock2.c: Splitting '10.24.18.180:5060' into... [Apr 8 16:03:14] DEBUG[19931] netsock2.c: ...host '10.24.18.180' and port '5060'. [Apr 8 16:03:14] DEBUG[19931] chan_sip.c: Allocating new SIP dialog for ca42de37-be0cae30-b2af0dd9@10.24.18.180 - REGISTER (No RTP) [Apr 8 16:03:14] DEBUG[19931] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Apr 8 16:03:14] DEBUG[19931] netsock2.c: Splitting '10.24.18.180:5060' into... [Apr 8 16:03:14] DEBUG[19931] netsock2.c: ...host '10.24.18.180' and port '5060'. [Apr 8 16:03:14] DEBUG[19931] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:03:14] DEBUG[19931] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:03:14] DEBUG[19931] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.24.18.180:5060 [Apr 8 16:03:14] DEBUG[19931] chan_sip.c: = Looking for Call ID: ca42de37-be0cae30-b2af0dd9@10.24.18.180 (Checking From) --From tag 7C9D6AA-C2FE3733 --To-tag [Apr 8 16:03:14] DEBUG[19931] netsock2.c: Splitting '10.24.18.124:5060' into... [Apr 8 16:03:14] DEBUG[19931] netsock2.c: ...host '10.24.18.124' and port '5060'. [Apr 8 16:03:14] DEBUG[19931] netsock2.c: Splitting '10.24.18.124:5060' into... [Apr 8 16:03:14] DEBUG[19931] netsock2.c: ...host '10.24.18.124' and port '5060'. [Apr 8 16:03:14] DEBUG[19931] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Apr 8 16:03:14] DEBUG[19931] netsock2.c: Splitting '10.24.18.180:5060' into... [Apr 8 16:03:14] DEBUG[19931] netsock2.c: ...host '10.24.18.180' and port '5060'. [Apr 8 16:03:14] DEBUG[19931] netsock2.c: Splitting '10.24.18.124' into... [Apr 8 16:03:14] DEBUG[19931] netsock2.c: ...host '10.24.18.124' and port ''. [Apr 8 16:03:14] DEBUG[19931] chan_sip.c: Store REGISTER's Contact header for call routing. [Apr 8 16:03:14] DEBUG[19931] netsock2.c: Splitting '10.24.18.180:5060' into... [Apr 8 16:03:14] DEBUG[19931] netsock2.c: ...host '10.24.18.180' and port '5060'. [Apr 8 16:03:14] DEBUG[19931] chan_sip.c: build_path: do not use Path headers [Apr 8 16:03:14] DEBUG[19931] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.24.18.180:5060 [Apr 8 16:03:14] DEBUG[19894] devicestate.c: No provider found, checking channel drivers for SIP - 6003 [Apr 8 16:03:14] DEBUG[19894] chan_sip.c: Checking device state for peer 6003 [Apr 8 16:03:14] DEBUG[19894] devicestate.c: Changing state for SIP/6003 - state 1 (Not in use) [Apr 8 16:03:17] DEBUG[20177][C-00000008] res_rtp_asterisk.c: Got RTCP report of 72 bytes [Apr 8 16:03:17] DEBUG[19931] chan_sip.c: = Looking for Call ID: 160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060 (Checking From) --From tag mLy8R5dLH38gw0LFeZTRFu16.YasQbAv --To-tag as23693ef2 [Apr 8 16:03:17] DEBUG[19931][C-00000008] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Apr 8 16:03:17] DEBUG[19931][C-00000008] netsock2.c: Splitting '10.24.18.138:5060' into... [Apr 8 16:03:17] DEBUG[19931][C-00000008] netsock2.c: ...host '10.24.18.138' and port '5060'. [Apr 8 16:03:17] DEBUG[19931][C-00000008] chan_sip.c: Setting SIP_ALREADYGONE on dialog 160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060 [Apr 8 16:03:17] DEBUG[19931][C-00000008] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f71d401bc88' [Apr 8 16:03:17] DEBUG[19931][C-00000008] chan_sip.c: Received bye, issuing owner hangup [Apr 8 16:03:17] DEBUG[19931][C-00000008] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.24.18.138:5060 [Apr 8 16:03:17] DEBUG[20177][C-00000008] bridge_channel.c: Setting 0x7f71d403c6e8(SIP/6002-0000001a) state from:0 to:1 [Apr 8 16:03:17] DEBUG[20177][C-00000008] bridge_channel.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: pulling 0x7f71d403c6e8(SIP/6002-0000001a) [Apr 8 16:03:17] VERBOSE[20177][C-00000008] bridge_channel.c: -- Channel SIP/6002-0000001a left 'simple_bridge' basic-bridge <2a99ac40-e5f3-4fff-a7c3-05e358e1fe42> [Apr 8 16:03:17] DEBUG[20177][C-00000008] bridge_channel.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: 0x7f71d403c6e8(SIP/6002-0000001a) is leaving simple_bridge technology [Apr 8 16:03:17] DEBUG[20177][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: dissolving bridge with cause 16(Normal Clearing) [Apr 8 16:03:17] DEBUG[20177][C-00000008] bridge_channel.c: Setting 0x7f71d402c548(SIP/6001-00000018) state from:0 to:2 [Apr 8 16:03:17] DEBUG[20177][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: queueing action type:13 sub:1001 [Apr 8 16:03:17] DEBUG[20177][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42 is dissolved, not performing smart bridge operation. [Apr 8 16:03:17] DEBUG[20174][C-00000008] bridge_channel.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: pulling 0x7f71d402c548(SIP/6001-00000018) [Apr 8 16:03:17] VERBOSE[20174][C-00000008] bridge_channel.c: -- Channel SIP/6001-00000018 left 'simple_bridge' basic-bridge <2a99ac40-e5f3-4fff-a7c3-05e358e1fe42> [Apr 8 16:03:17] DEBUG[20174][C-00000008] bridge_channel.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: 0x7f71d402c548(SIP/6001-00000018) is leaving simple_bridge technology [Apr 8 16:03:17] DEBUG[20174][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42 is dissolved, not performing smart bridge operation. [Apr 8 16:03:17] DEBUG[19896] cdr.c: Finalized CDR for SIP/6001-00000018 - start 1396990986.493447 answer 1396990986.493447 end 1396990997.310152 dispo ANSWERED [Apr 8 16:03:17] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Changing ssrc from 63844544 to 650692563 due to a source change [Apr 8 16:03:17] DEBUG[20177][C-00000008] channel.c: Hanging up channel 'SIP/6002-0000001a' [Apr 8 16:03:17] DEBUG[20177][C-00000008] chan_sip.c: Hangup call SIP/6002-0000001a, SIP callid 160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060 [Apr 8 16:03:17] DEBUG[20177][C-00000008] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f71d401bc88' [Apr 8 16:03:17] DEBUG[20174][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: actually destroying basic bridge, nobody wants it anymore [Apr 8 16:03:17] DEBUG[20174][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: calling basic bridge destructor [Apr 8 16:03:17] DEBUG[20174][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: calling simple_bridge technology stop [Apr 8 16:03:17] DEBUG[20174][C-00000008] bridge.c: Bridge 2a99ac40-e5f3-4fff-a7c3-05e358e1fe42: calling simple_bridge technology destructor [Apr 8 16:03:17] DEBUG[19896] cdr.c: CDR for SIP/6002-0000001a is dialed and has no Party B; discarding [Apr 8 16:03:17] DEBUG[19894] devicestate.c: No provider found, checking channel drivers for SIP - 6002 [Apr 8 16:03:17] DEBUG[19894] chan_sip.c: Checking device state for peer 6002 [Apr 8 16:03:17] DEBUG[19894] devicestate.c: Changing state for SIP/6002 - state 1 (Not in use) [Apr 8 16:03:17] DEBUG[20174][C-00000008] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Apr 8 16:03:17] DEBUG[20174][C-00000008] pbx.c: Spawn extension (agi-test-context,12,1) exited non-zero on 'SIP/6001-00000018' [Apr 8 16:03:17] VERBOSE[20174][C-00000008] pbx.c: == Spawn extension (agi-test-context, 12, 1) exited non-zero on 'SIP/6001-00000018' [Apr 8 16:03:17] DEBUG[20174][C-00000008] channel.c: Soft-Hanging up channel 'SIP/6001-00000018' [Apr 8 16:03:17] DEBUG[20174][C-00000008] channel.c: Soft-Hanging up channel 'SIP/6001-00000018' [Apr 8 16:03:17] DEBUG[20174][C-00000008] pbx.c: Result of 'EXTEN' is 'h' [Apr 8 16:03:17] DEBUG[20174][C-00000008] pbx.c: Result of 'ORGDEST' is NULL [Apr 8 16:03:17] DEBUG[20174][C-00000008] pbx.c: Launching 'NoOp' [Apr 8 16:03:17] VERBOSE[20174][C-00000008] pbx.c: -- Executing [h@agi-test-context:1] NoOp("SIP/6001-00000018", ""po AGI ===================="h" """) in new stack [Apr 8 16:03:17] DEBUG[20174][C-00000008] pbx.c: Launching 'Hangup' [Apr 8 16:03:17] VERBOSE[20174][C-00000008] pbx.c: -- Executing [h@agi-test-context:2] Hangup("SIP/6001-00000018", "") in new stack [Apr 8 16:03:17] DEBUG[20174][C-00000008] channel.c: Soft-Hanging up channel 'SIP/6001-00000018' [Apr 8 16:03:17] DEBUG[20174][C-00000008] pbx.c: Spawn extension (agi-test-context,h,2) exited non-zero on 'SIP/6001-00000018' [Apr 8 16:03:17] VERBOSE[20174][C-00000008] pbx.c: == Spawn extension (agi-test-context, h, 2) exited non-zero on 'SIP/6001-00000018' [Apr 8 16:03:17] DEBUG[20174][C-00000008] channel.c: Hanging up channel 'SIP/6001-00000018' [Apr 8 16:03:17] DEBUG[20174][C-00000008] chan_sip.c: Hangup call SIP/6001-00000018, SIP callid 1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv [Apr 8 16:03:17] DEBUG[20174][C-00000008] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f717002bb28' [Apr 8 16:03:17] DEBUG[20174][C-00000008] chan_sip.c: Session timer stopped: 677 - 1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv [Apr 8 16:03:17] DEBUG[20174][C-00000008] netsock2.c: Splitting '10.24.18.16:5060' into... [Apr 8 16:03:17] DEBUG[20174][C-00000008] netsock2.c: ...host '10.24.18.16' and port '5060'. [Apr 8 16:03:17] DEBUG[20174][C-00000008] chan_sip.c: Trying to put 'BYE sip:600' onto UDP socket destined for 10.24.18.16:5060 [Apr 8 16:03:17] DEBUG[19894] devicestate.c: No provider found, checking channel drivers for SIP - 6001 [Apr 8 16:03:17] DEBUG[19894] chan_sip.c: Checking device state for peer 6001 [Apr 8 16:03:17] DEBUG[19894] devicestate.c: Changing state for SIP/6001 - state 1 (Not in use) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(src)})' (from 'CSV_QUOTE(${CDR(src)})},"Destination":${CSV_QUOTE(${CDR(dst)})},"Context":${CSV_QUOTE(${CDR(dcontext)})},"SourceChannel":${CSV_QUOTE(${CDR(channel)})},"DestinationChannel":${CSV_QUOTE(${CDR(dstchannel)})},"LastAPP":${CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 22) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(src)' (from 'CDR(src)})' len 8) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(src) result is '6001' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(6001) result is '"6001"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(dst)})' (from 'CSV_QUOTE(${CDR(dst)})},"Context":${CSV_QUOTE(${CDR(dcontext)})},"SourceChannel":${CSV_QUOTE(${CDR(channel)})},"DestinationChannel":${CSV_QUOTE(${CDR(dstchannel)})},"LastAPP":${CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 22) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(dst)' (from 'CDR(dst)})' len 8) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(dst) result is '1' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(1) result is '"1"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(dcontext)})' (from 'CSV_QUOTE(${CDR(dcontext)})},"SourceChannel":${CSV_QUOTE(${CDR(channel)})},"DestinationChannel":${CSV_QUOTE(${CDR(dstchannel)})},"LastAPP":${CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 27) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(dcontext)' (from 'CDR(dcontext)})' len 13) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(dcontext) result is 'agi-test-context' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(agi-test-context) result is '"agi-test-context"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(channel)})' (from 'CSV_QUOTE(${CDR(channel)})},"DestinationChannel":${CSV_QUOTE(${CDR(dstchannel)})},"LastAPP":${CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 26) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(channel)' (from 'CDR(channel)})' len 12) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(channel) result is 'SIP/6001-00000018' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(SIP/6001-00000018) result is '"SIP/6001-00000018"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(dstchannel)})' (from 'CSV_QUOTE(${CDR(dstchannel)})},"LastAPP":${CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 29) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(dstchannel)' (from 'CDR(dstchannel)})' len 15) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(dstchannel) result is 'SIP/6004-00000019' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(SIP/6004-00000019) result is '"SIP/6004-00000019"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(lastapp)})' (from 'CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 26) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(lastapp)' (from 'CDR(lastapp)})' len 12) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(lastapp) result is 'Dial' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(Dial) result is '"Dial"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(lastdata)})' (from 'CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 27) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(lastdata)' (from 'CDR(lastdata)})' len 13) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(lastdata) result is 'SIP/6004' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(SIP/6004) result is '"SIP/6004"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(start)})' (from 'CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 24) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(start)' (from 'CDR(start)})' len 10) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(start) result is '2014-04-08 16:02:52' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(2014-04-08 16:02:52) result is '"2014-04-08 16:02:52"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(answer)})' (from 'CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 25) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(answer)' (from 'CDR(answer)})' len 11) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(answer) result is '2014-04-08 16:02:52' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(2014-04-08 16:02:52) result is '"2014-04-08 16:02:52"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(end)})' (from 'CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 22) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(end)' (from 'CDR(end)})' len 8) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(end) result is '2014-04-08 16:03:06' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(2014-04-08 16:03:06) result is '"2014-04-08 16:03:06"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(duration,f)})' (from 'CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 29) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(duration,f)' (from 'CDR(duration,f)})' len 15) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(duration,f) result is '0.014000' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(0.014000) result is '"0.014000"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(billsec,f)})' (from 'CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 28) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(billsec,f)' (from 'CDR(billsec,f)})' len 14) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(billsec,f) result is '0.014000' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(0.014000) result is '"0.014000"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(disposition)})' (from 'CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 30) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(disposition)' (from 'CDR(disposition)})' len 16) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(disposition) result is 'ANSWERED' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(ANSWERED) result is '"ANSWERED"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(amaflags)})' (from 'CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 27) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(amaflags)' (from 'CDR(amaflags)})' len 13) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(amaflags) result is 'DOCUMENTATION' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(DOCUMENTATION) result is '"DOCUMENTATION"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(accountcode)})' (from 'CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 30) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(accountcode)' (from 'CDR(accountcode)})' len 16) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(accountcode) result is '' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE() result is '""' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(uniqueid)})' (from 'CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 27) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(uniqueid)' (from 'CDR(uniqueid)})' len 13) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(uniqueid) result is '1396990972.40' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(1396990972.40) result is '"1396990972.40"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(userfield)})' (from 'CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 28) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(userfield)' (from 'CDR(userfield)})' len 14) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(userfield) result is '' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE() result is '""' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(sequence)' (from 'CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 13) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(sequence) result is '32' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(acustomfield1)})' (from 'CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 32) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(acustomfield1)' (from 'CDR(acustomfield1)})' len 18) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(acustomfield1) result is '' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE() result is '""' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(acustomfield2)})' (from 'CSV_QUOTE(${CDR(acustomfield2)})}} ' len 32) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(acustomfield2)' (from 'CDR(acustomfield2)})' len 18) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(acustomfield2) result is '' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE() result is '""' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(src)})' (from 'CSV_QUOTE(${CDR(src)})},"Destination":${CSV_QUOTE(${CDR(dst)})},"Context":${CSV_QUOTE(${CDR(dcontext)})},"SourceChannel":${CSV_QUOTE(${CDR(channel)})},"DestinationChannel":${CSV_QUOTE(${CDR(dstchannel)})},"LastAPP":${CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 22) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(src)' (from 'CDR(src)})' len 8) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(src) result is '6001' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(6001) result is '"6001"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(dst)})' (from 'CSV_QUOTE(${CDR(dst)})},"Context":${CSV_QUOTE(${CDR(dcontext)})},"SourceChannel":${CSV_QUOTE(${CDR(channel)})},"DestinationChannel":${CSV_QUOTE(${CDR(dstchannel)})},"LastAPP":${CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 22) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(dst)' (from 'CDR(dst)})' len 8) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(dst) result is '12' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(12) result is '"12"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(dcontext)})' (from 'CSV_QUOTE(${CDR(dcontext)})},"SourceChannel":${CSV_QUOTE(${CDR(channel)})},"DestinationChannel":${CSV_QUOTE(${CDR(dstchannel)})},"LastAPP":${CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 27) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(dcontext)' (from 'CDR(dcontext)})' len 13) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(dcontext) result is 'agi-test-context' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(agi-test-context) result is '"agi-test-context"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(channel)})' (from 'CSV_QUOTE(${CDR(channel)})},"DestinationChannel":${CSV_QUOTE(${CDR(dstchannel)})},"LastAPP":${CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 26) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(channel)' (from 'CDR(channel)})' len 12) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(channel) result is 'SIP/6001-00000018' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(SIP/6001-00000018) result is '"SIP/6001-00000018"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(dstchannel)})' (from 'CSV_QUOTE(${CDR(dstchannel)})},"LastAPP":${CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 29) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(dstchannel)' (from 'CDR(dstchannel)})' len 15) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(dstchannel) result is 'SIP/6002-0000001a' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(SIP/6002-0000001a) result is '"SIP/6002-0000001a"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(lastapp)})' (from 'CSV_QUOTE(${CDR(lastapp)})},"LastData":${CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 26) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(lastapp)' (from 'CDR(lastapp)})' len 12) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(lastapp) result is 'Dial' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(Dial) result is '"Dial"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(lastdata)})' (from 'CSV_QUOTE(${CDR(lastdata)})},"Start":${CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 27) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(lastdata)' (from 'CDR(lastdata)})' len 13) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(lastdata) result is 'SIP/6002,45,Tt' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(SIP/6002,45,Tt) result is '"SIP/6002,45,Tt"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(start)})' (from 'CSV_QUOTE(${CDR(start)})},"Answer":${CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 24) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(start)' (from 'CDR(start)})' len 10) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(start) result is '2014-04-08 16:03:06' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(2014-04-08 16:03:06) result is '"2014-04-08 16:03:06"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(answer)})' (from 'CSV_QUOTE(${CDR(answer)})},"End":${CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 25) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(answer)' (from 'CDR(answer)})' len 11) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(answer) result is '2014-04-08 16:03:06' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(2014-04-08 16:03:06) result is '"2014-04-08 16:03:06"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(end)})' (from 'CSV_QUOTE(${CDR(end)})},"Duration":${CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 22) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(end)' (from 'CDR(end)})' len 8) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(end) result is '2014-04-08 16:03:17' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(2014-04-08 16:03:17) result is '"2014-04-08 16:03:17"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(duration,f)})' (from 'CSV_QUOTE(${CDR(duration,f)})},"BillSec":${CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 29) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(duration,f)' (from 'CDR(duration,f)})' len 15) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(duration,f) result is '0.010000' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(0.010000) result is '"0.010000"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(billsec,f)})' (from 'CSV_QUOTE(${CDR(billsec,f)})},"Disposition":${CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 28) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(billsec,f)' (from 'CDR(billsec,f)})' len 14) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(billsec,f) result is '0.010000' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(0.010000) result is '"0.010000"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(disposition)})' (from 'CSV_QUOTE(${CDR(disposition)})},"amaFlags":${CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 30) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(disposition)' (from 'CDR(disposition)})' len 16) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(disposition) result is 'ANSWERED' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(ANSWERED) result is '"ANSWERED"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(amaflags)})' (from 'CSV_QUOTE(${CDR(amaflags)})},"AccountCode":${CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 27) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(amaflags)' (from 'CDR(amaflags)})' len 13) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(amaflags) result is 'DOCUMENTATION' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(DOCUMENTATION) result is '"DOCUMENTATION"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(accountcode)})' (from 'CSV_QUOTE(${CDR(accountcode)})},"UniqueID":${CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 30) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(accountcode)' (from 'CDR(accountcode)})' len 16) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(accountcode) result is '' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE() result is '""' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(uniqueid)})' (from 'CSV_QUOTE(${CDR(uniqueid)})},"UserField":${CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 27) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(uniqueid)' (from 'CDR(uniqueid)})' len 13) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(uniqueid) result is '1396990972.40' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE(1396990972.40) result is '"1396990972.40"' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(userfield)})' (from 'CSV_QUOTE(${CDR(userfield)})},"Sequence":${CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 28) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(userfield)' (from 'CDR(userfield)})' len 14) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(userfield) result is '' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE() result is '""' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(sequence)' (from 'CDR(sequence)},"acustomfield1":${CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 13) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(sequence) result is '35' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(acustomfield1)})' (from 'CSV_QUOTE(${CDR(acustomfield1)})},"acustomfield2":${CSV_QUOTE(${CDR(acustomfield2)})}} ' len 32) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(acustomfield1)' (from 'CDR(acustomfield1)})' len 18) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(acustomfield1) result is '' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE() result is '""' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CSV_QUOTE(${CDR(acustomfield2)})' (from 'CSV_QUOTE(${CDR(acustomfield2)})}} ' len 32) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Evaluating 'CDR(acustomfield2)' (from 'CDR(acustomfield2)})' len 18) [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CDR(acustomfield2) result is '' [Apr 8 16:03:17] DEBUG[19896] pbx.c: Function CSV_QUOTE() result is '""' [Apr 8 16:03:17] DEBUG[19931] chan_sip.c: = Looking for Call ID: 1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv (Checking To) --From tag as33ca3798 --To-tag FWJ0LyMfT9T6s6nmXo-k5Cm2z-V3PeiV [Apr 8 16:03:17] DEBUG[19931][C-00000008] chan_sip.c: Stopping retransmission on '1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv' of Request 102: Match Found [Apr 8 16:03:17] DEBUG[19931] chan_sip.c: Destroying SIP dialog 1Clhez9ZlHHHPIoEYtvoFYQtORAfprXv [Apr 8 16:03:17] DEBUG[19931] rtp_engine.c: Destroyed RTP instance '0x7f717002bb28' [Apr 8 16:03:37] VERBOSE[20135] asterisk.c: -- Remote UNIX connection disconnected [Apr 8 16:03:39] DEBUG[19931] chan_sip.c: Auto destroying SIP dialog '8323200811233-281921055718516@10.24.18.166' [Apr 8 16:03:39] DEBUG[19931] chan_sip.c: Destroying SIP dialog 8323200811233-281921055718516@10.24.18.166 [Apr 8 16:03:40] DEBUG[19931] chan_sip.c: Auto destroying SIP dialog '0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060' [Apr 8 16:03:40] DEBUG[19931] chan_sip.c: Destroying SIP dialog 0fcdf64055f60df8764a6d5b6fc8a652@10.24.18.124:5060 [Apr 8 16:03:40] DEBUG[19931] rtp_engine.c: Destroyed RTP instance '0x7f71d4009a18' [Apr 8 16:03:46] DEBUG[19931] chan_sip.c: Auto destroying SIP dialog 'ca42de37-be0cae30-b2af0dd9@10.24.18.180' [Apr 8 16:03:46] DEBUG[19931] chan_sip.c: Destroying SIP dialog ca42de37-be0cae30-b2af0dd9@10.24.18.180 [Apr 8 16:03:49] DEBUG[19931] chan_sip.c: Auto destroying SIP dialog '160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060' [Apr 8 16:03:49] DEBUG[19931] chan_sip.c: Destroying SIP dialog 160b828578330ec732d0f6fe26bcda57@10.24.18.124:5060 [Apr 8 16:03:49] DEBUG[19931] rtp_engine.c: Destroyed RTP instance '0x7f71d401bc88'