[May  8 10:27:02] DEBUG[15182][C-0000034c] pbx.c: Launching 'Dial'
[May  8 10:27:02] VERBOSE[15182][C-0000034c] pbx.c:     -- Executing [SIP9001@phones:1] Dial("IAX2/auckland-12923", "SIP/SIP9001") in new stack
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: Asked to create a SIP channel with formats: (alaw)
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: Allocating new SIP dialog for 7b6575912d02bd333228d7d92013d337@192.168.ast.rix:5060 - INVITE (No RTP)
[May  8 10:27:02] DEBUG[15182][C-0000034c] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x1061b7d4'
[May  8 10:27:02] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Allocated port 10654 for RTP instance '0x1061b7d4'
[May  8 10:27:02] DEBUG[15182][C-0000034c] rtp_engine.c: RTP instance '0x1061b7d4' is setup and ready to go
[May  8 10:27:02] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x1061b7d4'
[May  8 10:27:02] VERBOSE[15182][C-0000034c] netsock2.c:   == Using SIP RTP CoS mark 5
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: Setting NAT on RTP to Off
[May  8 10:27:02] DEBUG[15182][C-0000034c] acl.c: For destination '192.168.recep.tion', our source address is '192.168.ast.rix'.
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.ast.rix:5060
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: NAT detected for 192.168.ast.rix:5060 / 192.168.recep.tion:5060
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: Setting NAT on RTP to Off
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: SIP call-id changed from '7b6575912d02bd333228d7d92013d337@192.168.ast.rix:5060' to '0e9a5bc50d97162a41b20f7d61aef3b9@192.168.ast.rix:5060'
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: *** Our native formats are (alaw) 
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: *** Joint capabilities are (alaw) 
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: *** Our capabilities are (gsm|ulaw|alaw) 
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw 
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: *** Our preferred formats from the incoming channel are (alaw) 
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: This channel will not be able to handle video.
[May  8 10:27:02] DEBUG[15182][C-0000034c] channel_internal_api.c: Channel Call ID changing from [C-0000034c] to [C-0000034c]
[May  8 10:27:02] DEBUG[15182][C-0000034c] rtp_engine.c: Can't find native functions for channel 'IAX2/auckland-12923'
[May  8 10:27:02] DEBUG[15182][C-0000034c] channel.c: Not copying variable DIALEDTIME.
[May  8 10:27:02] DEBUG[15182][C-0000034c] channel.c: Not copying variable ANSWEREDTIME.
[May  8 10:27:02] DEBUG[15182][C-0000034c] channel.c: Not copying variable DIALEDPEERNAME.
[May  8 10:27:02] DEBUG[15182][C-0000034c] channel.c: Not copying variable DIALEDPEERNUMBER.
[May  8 10:27:02] DEBUG[15182][C-0000034c] channel.c: Not copying variable DIALSTATUS.
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: Outgoing Call for SIP9001
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: Updating call counter for outgoing call
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: ** Our capability: (gsm|ulaw|alaw) Video flag: False Text flag: False
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: ** Our prefcodec: (alaw) 
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: -- Done with adding codecs to SDP
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: Done building SDP. Settling with this capability: (gsm|ulaw|alaw)
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: Initializing initreq for method INVITE - callid 0e9a5bc50d97162a41b20f7d61aef3b9@192.168.ast.rix:5060
[May  8 10:27:02] DEBUG[15182][C-0000034c] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:02] VERBOSE[15182][C-0000034c] app_dial.c:     -- Called SIP/SIP9001
[May  8 10:27:02] DEBUG[19838][C-0000034c] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0e9a5bc50d97162a41b20f7d61aef3b9@192.168.ast.rix:5060' Request 102: Found
[May  8 10:27:02] DEBUG[19838][C-0000034c] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0e9a5bc50d97162a41b20f7d61aef3b9@192.168.ast.rix:5060' Request 102: Found
[May  8 10:27:02] DEBUG[19838][C-0000034c] chan_sip.c: build_route: Contact hop: <sip:SIP9001@192.168.recep.tion:5060;transport=udp>
[May  8 10:27:02] VERBOSE[15182][C-0000034c] app_dial.c:     -- SIP/SIP9001-000001e2 is ringing
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Acked pending invite 102
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Stopping retransmission on '0e9a5bc50d97162a41b20f7d61aef3b9@192.168.ast.rix:5060' of Request 102: Match Found
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Processing session-level SDP o=SIP9001 8000 8000 IN IP4 192.168.recep.tion... OK.
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Processing session-level SDP s=SIP Call... UNSUPPORTED OR FAILED.
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.recep.tion... OK.
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[May  8 10:27:11] DEBUG[19838][C-0000034c] rtp_engine.c: Setting payload 8 based on m type on 0xb51f9e10
[May  8 10:27:11] DEBUG[19838][C-0000034c] rtp_engine.c: Setting payload 101 based on m type on 0xb51f9e10
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK.
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK.
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED.
[May  8 10:27:11] DEBUG[19838][C-0000034c] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1061b7d4'
[May  8 10:27:11] DEBUG[19838][C-0000034c] rtp_engine.c: Copying payload 8 from 0xb51f9e10 to 0x1061b980
[May  8 10:27:11] DEBUG[19838][C-0000034c] rtp_engine.c: Copying payload 101 from 0xb51f9e10 to 0x1061b980
[May  8 10:27:11] DEBUG[19838][C-0000034c] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x1061b7d4'
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: We're settling with these formats: (alaw)
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Updating call counter for outgoing call
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: build_route: Contact hop: <sip:SIP9001@192.168.recep.tion:5060;transport=udp>
[May  8 10:27:11] DEBUG[19838][C-0000034c] chan_sip.c: Trying to put 'ACK sip:GXP' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:11] VERBOSE[15182][C-0000034c] app_dial.c:     -- SIP/SIP9001-000001e2 answered IAX2/auckland-12923
[May  8 10:27:11] DEBUG[15182][C-0000034c] chan_iax2.c: Answering IAX2 call
[May  8 10:27:11] DEBUG[15182][C-0000034c] features.c: Removing dialed interfaces datastore on SIP/SIP9001-000001e2 since we're bridging
[May  8 10:27:11] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:11] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:11] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:11] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:11] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw
[May  8 10:27:11] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160
[May  8 10:27:11] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x1061b7d4'
[May  8 10:27:11] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: 0x1063f408 -- Probation learning mode pass with source address 192.168.recep.tion:5050
[May  8 10:27:30] DEBUG[15182][C-0000034c] channel.c: Deadlock avoided for write to channel 'SIP/SIP9001-000001e2'
[May  8 10:27:30] DEBUG[19838][C-0000034c] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces, timer, path"
[May  8 10:27:30] DEBUG[19838][C-0000034c] sip/reqresp_parser.c: Found SIP option: -replaces-
[May  8 10:27:30] DEBUG[19838][C-0000034c] sip/reqresp_parser.c: Matched SIP option: replaces
[May  8 10:27:30] DEBUG[19838][C-0000034c] sip/reqresp_parser.c: Found SIP option: -timer-
[May  8 10:27:30] DEBUG[19838][C-0000034c] sip/reqresp_parser.c: Matched SIP option: timer
[May  8 10:27:30] DEBUG[19838][C-0000034c] sip/reqresp_parser.c: Found SIP option: -path-
[May  8 10:27:30] DEBUG[19838][C-0000034c] sip/reqresp_parser.c: Matched SIP option: path
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing session-level SDP o=SIP9001 8000 8001 IN IP4 192.168.recep.tion... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing session-level SDP s=SIP Call... UNSUPPORTED OR FAILED.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing session-level SDP c=IN IP4 0.0.0.0... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Setting payload 8 based on m type on 0xb51f9e60
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Setting payload 0 based on m type on 0xb51f9e60
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Setting payload 3 based on m type on 0xb51f9e60
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Setting payload 18 based on m type on 0xb51f9e60
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Setting payload 2 based on m type on 0xb51f9e60
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Setting payload 4 based on m type on 0xb51f9e60
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Setting payload 9 based on m type on 0xb51f9e60
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Setting payload 101 based on m type on 0xb51f9e60
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=sendonly... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:2 G726-32/8000... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:4 G723/8000... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED.
[May  8 10:27:30] DEBUG[19838][C-0000034c] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1061b7d4'
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Copying payload 0 from 0xb51f9e60 to 0x1061b980
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Copying payload 2 from 0xb51f9e60 to 0x1061b980
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Copying payload 3 from 0xb51f9e60 to 0x1061b980
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Copying payload 4 from 0xb51f9e60 to 0x1061b980
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Copying payload 8 from 0xb51f9e60 to 0x1061b980
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Copying payload 9 from 0xb51f9e60 to 0x1061b980
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Copying payload 18 from 0xb51f9e60 to 0x1061b980
[May  8 10:27:30] DEBUG[19838][C-0000034c] rtp_engine.c: Copying payload 101 from 0xb51f9e60 to 0x1061b980
[May  8 10:27:30] DEBUG[19838][C-0000034c] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x1061b7d4'
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: We're settling with these formats: (gsm|ulaw|alaw)
[May  8 10:27:30] DEBUG[19838][C-0000034c] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1061b7d4'
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Incoming INVITE with 'timer' option supported
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: SIP/SIP9001-000001e2: This call is UP.... 
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Setting framing from config on incoming call
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: ** Our capability: (gsm|ulaw|alaw) Video flag: True Text flag: True
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: ** Our prefcodec: (alaw) 
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: -- Done with adding codecs to SDP
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Done building SDP. Settling with this capability: (gsm|ulaw|alaw)
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] VERBOSE[15182][C-0000034c] res_musiconhold.c:     -- Started music on hold, class 'default', on IAX2/auckland-12923
[May  8 10:27:30] DEBUG[15182][C-0000034c] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] channel.c: Got a FRAME_CONTROL (32) frame on channel SIP/SIP9001-000001e2
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:30] DEBUG[15182][C-0000034c] channel.c: Bridge stops bridging channels IAX2/auckland-12923 and SIP/SIP9001-000001e2
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[19838][C-0000034c] chan_sip.c: Stopping retransmission on '0e9a5bc50d97162a41b20f7d61aef3b9@192.168.ast.rix:5060' of Response 5337: Match Found
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] channel.c: Set channel IAX2/auckland-12923 to write format slin
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_musiconhold.c: IAX2/auckland-12923 Opened file 0 '/var/lib/asterisk/moh-bdt/comfort-mono8k'
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:30] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
<snip repeated lines>
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] DEBUG[19838][C-0000034d] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces, timer, path"
[May  8 10:27:34] DEBUG[19838][C-0000034d] sip/reqresp_parser.c: Found SIP option: -replaces-
[May  8 10:27:34] DEBUG[19838][C-0000034d] sip/reqresp_parser.c: Matched SIP option: replaces
[May  8 10:27:34] DEBUG[19838][C-0000034d] sip/reqresp_parser.c: Found SIP option: -timer-
[May  8 10:27:34] DEBUG[19838][C-0000034d] sip/reqresp_parser.c: Matched SIP option: timer
[May  8 10:27:34] DEBUG[19838][C-0000034d] sip/reqresp_parser.c: Found SIP option: -path-
[May  8 10:27:34] DEBUG[19838][C-0000034d] sip/reqresp_parser.c: Matched SIP option: path
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Stopping retransmission on 'c0214243732214b8@192.168.recep.tion' of Response 443: Match Found
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x10604854'
[May  8 10:27:34] DEBUG[19838][C-0000034d] res_rtp_asterisk.c: Allocated port 11154 for RTP instance '0x10604854'
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: RTP instance '0x10604854' is setup and ready to go
[May  8 10:27:34] DEBUG[19838][C-0000034d] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x10604854'
[May  8 10:27:34] VERBOSE[19838][C-0000034d] netsock2.c:   == Using SIP RTP CoS mark 5
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Setting NAT on RTP to Off
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing session-level SDP o=SIP9001 8001 8001 IN IP4 192.168.recep.tion... OK.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing session-level SDP s=SIP Call... UNSUPPORTED OR FAILED.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.recep.tion... OK.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 8 based on m type on 0xb51f9e60
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 0 based on m type on 0xb51f9e60
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 3 based on m type on 0xb51f9e60
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 18 based on m type on 0xb51f9e60
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 2 based on m type on 0xb51f9e60
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 4 based on m type on 0xb51f9e60
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 9 based on m type on 0xb51f9e60
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 101 based on m type on 0xb51f9e60
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK.
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:2 G726-32/8000... OK.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:4 G723/8000... OK.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED.
[May  8 10:27:34] DEBUG[19838][C-0000034d] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x10604854'
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 0 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 2 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 3 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 4 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 8 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 9 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 18 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:34] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 101 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:34] DEBUG[19838][C-0000034d] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x10604854'
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: We're settling with these formats: (gsm|ulaw|alaw)
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Checking SIP call limits for device SIP9001
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Updating call counter for incoming call
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: *** Our native formats are (alaw) 
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: *** Joint capabilities are (gsm|ulaw|alaw) 
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: *** Our capabilities are (gsm|ulaw|alaw) 
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw 
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: This channel will not be able to handle video.
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: build_route: Contact hop: <sip:SIP9001@192.168.recep.tion:5060;transport=udp>
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Incoming INVITE with 'timer' option supported
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Session timer started: 651465 - c0214243732214b8@192.168.recep.tion
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: SIP/SIP9001-000001e3: New call is still down.... Trying... 
[May  8 10:27:34] DEBUG[19838][C-0000034d] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:34] DEBUG[15185][C-0000034d] pbx.c: Launching 'Dial'
[May  8 10:27:34] VERBOSE[15185][C-0000034d] pbx.c:     -- Executing [8554@phones:1] Dial("SIP/SIP9001-000001e3", "IAX2/auckland/8554,,r") in new stack
[May  8 10:27:34] DEBUG[15185][C-0000034d] chan_iax2.c: ip callno count incremented to 5 for 192.168.4.40
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] DEBUG[15185][C-0000034d] chan_iax2.c: Made call 13734 into trunk call 16803
[May  8 10:27:34] DEBUG[15185][C-0000034d] channel_internal_api.c: Channel Call ID changing from [C-0000034d] to [C-0000034d]
[May  8 10:27:34] DEBUG[15185][C-0000034d] channel_internal_api.c: Channel Call ID changing from [C-0000034d] to [C-0000034d]
[May  8 10:27:34] DEBUG[15185][C-0000034d] rtp_engine.c: Can't find native functions for channel 'IAX2/auckland-16803'
[May  8 10:27:34] DEBUG[15185][C-0000034d] channel.c: Not copying variable DIALEDTIME.
[May  8 10:27:34] DEBUG[15185][C-0000034d] channel.c: Not copying variable ANSWEREDTIME.
[May  8 10:27:34] DEBUG[15185][C-0000034d] channel.c: Not copying variable DIALEDPEERNAME.
[May  8 10:27:34] DEBUG[15185][C-0000034d] channel.c: Not copying variable DIALEDPEERNUMBER.
[May  8 10:27:34] DEBUG[15185][C-0000034d] channel.c: Not copying variable DIALSTATUS.
[May  8 10:27:34] DEBUG[15185][C-0000034d] channel.c: Not copying variable SIPCALLID.
[May  8 10:27:34] DEBUG[15185][C-0000034d] channel.c: Not copying variable SIPDOMAIN.
[May  8 10:27:34] DEBUG[15185][C-0000034d] channel.c: Not copying variable SIPURI.
[May  8 10:27:34] DEBUG[15185][C-0000034d] chan_iax2.c: prepending alaw to prefs
[May  8 10:27:34] VERBOSE[15185][C-0000034d] app_dial.c:     -- Called IAX2/auckland/8554
[May  8 10:27:34] DEBUG[15185][C-0000034d] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] VERBOSE[19830][C-0000034d] chan_iax2.c:     -- Call accepted by 192.168.4.40 (format alaw)
[May  8 10:27:34] VERBOSE[19830][C-0000034d] chan_iax2.c:     -- Format for call is (alaw)
[May  8 10:27:34] DEBUG[19830][C-0000034d] channel.c: Set channel IAX2/auckland-16803 to write format alaw
[May  8 10:27:34] DEBUG[19830][C-0000034d] channel.c: Set channel IAX2/auckland-16803 to read format alaw
[May  8 10:27:34] VERBOSE[15185][C-0000034d] app_dial.c:     -- IAX2/auckland-16803 is proceeding passing it to SIP/SIP9001-000001e3
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] VERBOSE[15185][C-0000034d] app_dial.c:     -- IAX2/auckland-16803 is ringing
[May  8 10:27:34] DEBUG[15185][C-0000034d] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] VERBOSE[15185][C-0000034d] app_dial.c:     -- IAX2/auckland-16803 is ringing
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:34] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
<snip repeated lines>
[May  8 10:27:40] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:40] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:40] VERBOSE[15185][C-0000034d] app_dial.c:     -- IAX2/auckland-16803 answered SIP/SIP9001-000001e3
[May  8 10:27:40] DEBUG[15185][C-0000034d] chan_sip.c: SIP answering channel: SIP/SIP9001-000001e3
[May  8 10:27:40] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:40] DEBUG[15185][C-0000034d] chan_sip.c: Setting framing from config on incoming call
[May  8 10:27:40] DEBUG[15185][C-0000034d] chan_sip.c: ** Our capability: (gsm|ulaw|alaw) Video flag: True Text flag: True
[May  8 10:27:40] DEBUG[15185][C-0000034d] chan_sip.c: ** Our prefcodec: (nothing) 
[May  8 10:27:40] DEBUG[15185][C-0000034d] chan_sip.c: -- Done with adding codecs to SDP
[May  8 10:27:40] DEBUG[15185][C-0000034d] chan_sip.c: Done building SDP. Settling with this capability: (gsm|ulaw|alaw)
[May  8 10:27:40] DEBUG[15185][C-0000034d] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:40] DEBUG[15185][C-0000034d] features.c: Removing dialed interfaces datastore on IAX2/auckland-16803 since we're bridging
[May  8 10:27:40] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:40] DEBUG[15185][C-0000034d] channel.c: Got a FRAME_CONTROL (-1) frame on channel IAX2/auckland-16803
[May  8 10:27:40] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:40] DEBUG[15185][C-0000034d] channel.c: Bridge stops bridging channels SIP/SIP9001-000001e3 and IAX2/auckland-16803
[May  8 10:27:40] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:40] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:40] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:40] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:40] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:40] DEBUG[19838][C-0000034d] chan_sip.c: Stopping retransmission on 'c0214243732214b8@192.168.recep.tion' of Response 444: Match Found
[May  8 10:27:40] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:40] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: 0x10589c68 -- Probation learning mode pass with source address 192.168.recep.tion:5052
[May  8 10:27:40] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:40] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
<snip repeated lines>
[May  8 10:27:41] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:41] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:41] DEBUG[19827][C-0000034d] chan_iax2.c: Ooh, voice format changed to 'alaw'
[May  8 10:27:41] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw
[May  8 10:27:41] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160
[May  8 10:27:41] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:41] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
<snip repeated lines>
[May  8 10:27:46] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:46] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing session-level SDP o=SIP9001 8001 8002 IN IP4 192.168.recep.tion... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing session-level SDP s=SIP Call... UNSUPPORTED OR FAILED.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.recep.tion... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 8 based on m type on 0xb51f9e60
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 0 based on m type on 0xb51f9e60
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 3 based on m type on 0xb51f9e60
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 18 based on m type on 0xb51f9e60
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 2 based on m type on 0xb51f9e60
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 4 based on m type on 0xb51f9e60
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 9 based on m type on 0xb51f9e60
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Setting payload 101 based on m type on 0xb51f9e60
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=sendonly... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:2 G726-32/8000... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:4 G723/8000... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED.
[May  8 10:27:46] DEBUG[19838][C-0000034d] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x10604854'
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 0 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 2 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 3 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 4 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 8 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 9 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 18 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:46] DEBUG[19838][C-0000034d] rtp_engine.c: Copying payload 101 from 0xb51f9e60 to 0x10604a00
[May  8 10:27:46] DEBUG[19838][C-0000034d] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x10604854'
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: We're settling with these formats: (gsm|ulaw|alaw)
[May  8 10:27:46] DEBUG[19838][C-0000034d] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x10604854'
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Incoming INVITE with 'timer' option supported
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: INVITE also has "Session-Expires" header.
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Session-Expires: 1800
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Refresher: UAS
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Restarting session-timers on a refresh - c0214243732214b8@192.168.recep.tion
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Session timer stopped: 651465 - c0214243732214b8@192.168.recep.tion
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Session timer started: 651474 - c0214243732214b8@192.168.recep.tion
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: SIP/SIP9001-000001e3: This call is UP.... 
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Setting framing from config on incoming call
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: ** Our capability: (gsm|ulaw|alaw) Video flag: True Text flag: True
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: ** Our prefcodec: (nothing) 
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: -- Done with adding codecs to SDP
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Done building SDP. Settling with this capability: (gsm|ulaw|alaw)
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:46] VERBOSE[15185][C-0000034d] res_musiconhold.c:     -- Started music on hold, class 'default', on IAX2/auckland-16803
[May  8 10:27:46] DEBUG[15185][C-0000034d] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[May  8 10:27:46] DEBUG[15185][C-0000034d] channel.c: Got a FRAME_CONTROL (32) frame on channel SIP/SIP9001-000001e3
[May  8 10:27:46] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:46] DEBUG[15185][C-0000034d] channel.c: Bridge stops bridging channels SIP/SIP9001-000001e3 and IAX2/auckland-16803
[May  8 10:27:46] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:46] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:46] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: No remote address on RTP instance '0x10604854' so dropping frame
[May  8 10:27:46] DEBUG[15185][C-0000034d] channel.c: Set channel IAX2/auckland-16803 to write format slin
[May  8 10:27:46] DEBUG[15185][C-0000034d] res_musiconhold.c: IAX2/auckland-16803 Opened file 0 '/var/lib/asterisk/moh-bdt/comfort-mono8k'
[May  8 10:27:46] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:46] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: No remote address on RTP instance '0x10604854' so dropping frame
[May  8 10:27:46] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:46] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: No remote address on RTP instance '0x10604854' so dropping frame
[May  8 10:27:46] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:46] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: No remote address on RTP instance '0x10604854' so dropping frame
[May  8 10:27:46] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: No remote address on RTP instance '0x10604854' so dropping frame
[May  8 10:27:46] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:46] DEBUG[19838][C-0000034d] chan_sip.c: Stopping retransmission on 'c0214243732214b8@192.168.recep.tion' of Response 445: Match Found
[May  8 10:27:46] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: No remote address on RTP instance '0x10604854' so dropping frame
[May  8 10:27:46] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
<snip repeated lines>
[May  8 10:27:46] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:47] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: No remote address on RTP instance '0x10604854' so dropping frame
[May  8 10:27:47] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:47] DEBUG[15185][C-0000034d] res_rtp_asterisk.c: No remote address on RTP instance '0x10604854' so dropping frame
[May  8 10:27:47] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: No remote address on RTP instance '0x1061b7d4' so dropping frame
[May  8 10:27:47] DEBUG[19838][C-0000034c] chan_sip.c: Attended transfer: Will use Replace-Call-ID : c0214243732214b8@192.168.recep.tion F-tag: dff9dad9d7ac54de T-tag: as1cd99136
[May  8 10:27:47] DEBUG[19838][C-0000034c] chan_sip.c: Trying to put 'SIP/2.0 202' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:47] DEBUG[19838][C-0000034c] chan_sip.c: SIP transfer: Four channels to handle
[May  8 10:27:47] VERBOSE[19838][C-0000034c] res_musiconhold.c:     -- Stopped music on hold on IAX2/auckland-12923
[May  8 10:27:47] DEBUG[19838][C-0000034c] channel.c: Set channel IAX2/auckland-12923 to write format alaw
[May  8 10:27:47] DEBUG[19838][C-0000034c] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[May  8 10:27:47] VERBOSE[19838][C-0000034c] res_musiconhold.c:     -- Stopped music on hold on IAX2/auckland-16803
[May  8 10:27:47] DEBUG[19838][C-0000034c] channel.c: Set channel IAX2/auckland-16803 to write format alaw
[May  8 10:27:47] DEBUG[19838][C-0000034c] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[May  8 10:27:47] DEBUG[19838][C-0000034c] channel.c: Planning to masquerade channel IAX2/auckland-12923 into the structure of SIP/SIP9001-000001e3
[May  8 10:27:47] DEBUG[19838][C-0000034c] channel.c: Done planning to masquerade channel IAX2/auckland-12923 into the structure of SIP/SIP9001-000001e3
[May  8 10:27:47] DEBUG[19838][C-0000034c] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:47] DEBUG[15185][C-0000034d] channel.c: Deadlock avoided for write to channel 'SIP/SIP9001-000001e3'
[May  8 10:27:47] DEBUG[19838][C-0000034c] channel.c: Putting channel IAX2/auckland-12923 in alaw/alaw formats
[May  8 10:27:47] DEBUG[19838][C-0000034c] chan_sip.c: SIP Fixup: New owner for dialogue c0214243732214b8@192.168.recep.tion: SIP/SIP9001-000001e3<ZOMBIE> (Old parent: IAX2/auckland-12923)
[May  8 10:27:47] DEBUG[19838][C-0000034c] channel.c: Done Masquerading IAX2/auckland-12923 (6)
[May  8 10:27:47] DEBUG[15182][C-0000034c] channel.c: Bridge stops because we're zombie or need a soft hangup: c0=SIP/SIP9001-000001e3<ZOMBIE>, c1=SIP/SIP9001-000001e2, flags: Yes,Yes,No,No
[May  8 10:27:47] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Setting the marker bit due to a source update
[May  8 10:27:47] DEBUG[15182][C-0000034c] channel.c: Bridge stops bridging channels SIP/SIP9001-000001e3<ZOMBIE> and SIP/SIP9001-000001e2
[May  8 10:27:47] DEBUG[15182][C-0000034c] cdr_mysql.c: Inserting a CDR record.
[May  8 10:27:47] DEBUG[15182][C-0000034c] cdr_mysql.c: SQL command as follows: INSERT INTO cdr (`calldate`,`clid`,`src`,`dst`,`dcontext`,`channel`,`dstchannel`,`lastapp`,`lastdata`,`duration`,`billsec`,`disposition`,`amaflags`,`uniqueid`,`dnid`) VALUES ('2013-05-08 10:27:02','\"CS:external\" <102825522499>','102825522499','SIP9001','phones','IAX2/auckland-12923','SIP/SIP9001-000001e2','Dial','SIP/SIP9001','45','36','ANSWERED','3','1367965622.1661','8554')
[May  8 10:27:47] DEBUG[15185][C-0000034d] channel.c: Returning from native bridge, channels: IAX2/auckland-12923, IAX2/auckland-16803
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '2013-05-08 10:27:02'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '"CS:external" <102825522499>'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'phones'
[May  8 10:27:47] DEBUG[15185][C-0000034d] channel.c: Returning from native bridge, channels: IAX2/auckland-12923, IAX2/auckland-16803
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'IAX2/auckland-12923'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'SIP/SIP9001-000001e2'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'Dial'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'SIP/SIP9001'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '45'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '36'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'ANSWERED'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'DOCUMENTATION'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '(null)'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '1367965622.1661'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '(null)'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '(null)'
[May  8 10:27:47] DEBUG[15182][C-0000034c] cdr_sqlite3_custom.c: About to log: INSERT INTO cdr (calldate,clid,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield,test) VALUES ('2013-05-08 10:27:02','"CS:external" <102825522499>','phones','IAX2/auckland-12923','SIP/SIP9001-000001e2','Dial','SIP/SIP9001','45','36','ANSWERED','DOCUMENTATION','','1367965622.1661','','')
[May  8 10:27:47] VERBOSE[19834][C-0000034d] chan_iax2.c:     -- Channel 'IAX2/auckland-16803' ready to transfer
[May  8 10:27:47] VERBOSE[19834][C-0000034d] chan_iax2.c:     -- Releasing IAX2/auckland-16803 and IAX2/auckland-12923
[May  8 10:27:47] DEBUG[19834][C-0000034d] sched.c: Attempted to delete nonexistent schedule entry 161234!
[May  8 10:27:47] ERROR[19834][C-0000034d] lock.c: chan_iax2.c line 1918 (iax2_destroy_helper): attempted unlock mutex '&iaxsl[pvt->callno]' without owning it!
[May  8 10:27:47] ERROR[19834][C-0000034d] lock.c: chan_iax2.c line 10178 (socket_process_helper): '&iaxsl[pvt->callno]' was locked here.
[May  8 10:27:47] DEBUG[19838][C-0000034c] chan_sip.c: Stopping retransmission on '0e9a5bc50d97162a41b20f7d61aef3b9@192.168.ast.rix:5060' of Request 103: Match Found
[May  8 10:27:47] NOTICE[19838][C-0000034c] chan_sip.c: Got OK on REFER Notify message
[May  8 10:27:47] ERROR[19834][C-0000034d] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/sbin/asterisk(ast_bt_get_addresses+0x19) [0x8139b21]
[May  8 10:27:47] ERROR[19834][C-0000034d] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/sbin/asterisk(__ast_pthread_mutex_lock+0xac) [0x8132d91]
[May  8 10:27:47] ERROR[19834][C-0000034d] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x3081f) [0xb69a781f]
[May  8 10:27:47] ERROR[19834][C-0000034d] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x3cf95) [0xb69b3f95]
[May  8 10:27:47] ERROR[19834][C-0000034d] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/lib/asterisk/modules/chan_iax2.so(+0x3d6f5) [0xb69b46f5]
[May  8 10:27:47] ERROR[19834][C-0000034d] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /usr/sbin/asterisk() [0x81ba6ab]
[May  8 10:27:47] ERROR[19834][C-0000034d] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /lib/i686/cmov/libpthread.so.0(+0x5955) [0xb7308955]
[May  8 10:27:47] ERROR[19834][C-0000034d] /usr/src/pbx/jan2011/asterisk-11/include/asterisk/lock.h: /lib/i686/cmov/libc.so.6(clone+0x5e) [0xb77481de]
[May  8 10:27:47] ERROR[19834][C-0000034d] lock.c: chan_iax2.c line 1918 (iax2_destroy_helper): Error releasing mutex: Operation not permitted
[May  8 10:27:47] DEBUG[19834][C-0000034d] chan_iax2.c: Received iseqno 15 not within window 17->19
[May  8 10:27:47] DEBUG[19838][C-0000034c] chan_sip.c: Setting SIP_ALREADYGONE on dialog 0e9a5bc50d97162a41b20f7d61aef3b9@192.168.ast.rix:5060
[May  8 10:27:47] DEBUG[19838][C-0000034c] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x1061b7d4'
[May  8 10:27:47] DEBUG[19838][C-0000034c] chan_sip.c: Received bye, issuing owner hangup
[May  8 10:27:47] DEBUG[19838][C-0000034c] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '"CS:external" <102825522499>'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '102825522499'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'SIP9001'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'phones'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'IAX2/auckland-12923'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'SIP/SIP9001-000001e2'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'Dial'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'SIP/SIP9001'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '2013-05-08 10:27:02'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '2013-05-08 10:27:11'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '2013-05-08 10:27:47'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '45'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '36'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'ANSWERED'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is 'DOCUMENTATION'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '(null)'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '1367965622.1661'
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Function result is '(null)'
[May  8 10:27:47] DEBUG[15182][C-0000034c] channel.c: Hanging up channel 'SIP/SIP9001-000001e2'
[May  8 10:27:47] DEBUG[15182][C-0000034c] chan_sip.c: Updating call counter for outgoing call
[May  8 10:27:47] DEBUG[15182][C-0000034c] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[May  8 10:27:47] DEBUG[15182][C-0000034c] pbx.c: Spawn extension (phones,SIP9001,1) exited non-zero on 'SIP/SIP9001-000001e3<ZOMBIE>'
[May  8 10:27:47] VERBOSE[15182][C-0000034c] pbx.c:   == Spawn extension (phones, SIP9001, 1) exited non-zero on 'SIP/SIP9001-000001e3<ZOMBIE>'
[May  8 10:27:47] DEBUG[15182][C-0000034c] channel.c: Soft-Hanging up channel 'SIP/SIP9001-000001e3<ZOMBIE>'
[May  8 10:27:47] DEBUG[15182][C-0000034c] channel.c: Hanging up channel 'SIP/SIP9001-000001e3<ZOMBIE>'
[May  8 10:27:47] DEBUG[15182][C-0000034c] chan_sip.c: Hangup call SIP/SIP9001-000001e3<ZOMBIE>, SIP callid c0214243732214b8@192.168.recep.tion
[May  8 10:27:47] DEBUG[15182][C-0000034c] chan_sip.c: Updating call counter for incoming call
[May  8 10:27:47] DEBUG[15182][C-0000034c] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x10604854'
[May  8 10:27:47] DEBUG[15182][C-0000034c] chan_sip.c: Session timer stopped: 651474 - c0214243732214b8@192.168.recep.tion
[May  8 10:27:47] DEBUG[15182][C-0000034c] chan_sip.c: Trying to put 'BYE sip:GXP' onto UDP socket destined for 192.168.recep.tion:5060
[May  8 10:27:47] DEBUG[19838][C-0000034d] chan_sip.c: Stopping retransmission on 'c0214243732214b8@192.168.recep.tion' of Request 102: Match Found