[May 23 18:57:31] Asterisk 11.2-cert1 built by root @ debMarketstar on a x86_64 running Linux on 2013-04-18 19:39:28 UTC
[May 23 18:57:31] DEBUG[31263] config.c: Parsing /etc/asterisk/logger.conf
[May 23 18:57:31] VERBOSE[31263] config.c:   == Parsing '/etc/asterisk/logger.conf': Found
[May 23 18:57:31] VERBOSE[31263] logger.c:  Asterisk Queue Logger restarted
[May 23 18:57:32] DEBUG[14921] chan_sip.c: Allocating new SIP dialog for 7a8240fb0d00ea7c478640853e2146b4@192.168.1.233:5060 - OPTIONS (No RTP)
[May 23 18:57:32] DEBUG[14921] acl.c: For destination '199.189.87.30', our source address is '201.217.134.244'.
[May 23 18:57:32] DEBUG[14921] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 201.217.134.244:5060
[May 23 18:57:32] DEBUG[14921] chan_sip.c: Initializing initreq for method OPTIONS - callid 421aadbd3997bb1061fe41d23aca4d48@201.217.134.244:5060
[May 23 18:57:32] DEBUG[14921] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 199.189.87.30:5060
[May 23 18:57:33] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 421aadbd3997bb1061fe41d23aca4d48@201.217.134.244:5060 (Checking To) --From tag as2968cb5c --To-tag as1157f36a  
[May 23 18:57:33] DEBUG[14921] chan_sip.c: Stopping retransmission on '421aadbd3997bb1061fe41d23aca4d48@201.217.134.244:5060' of Request 102: Match Found
[May 23 18:57:33] DEBUG[14921] chan_sip.c: Destroying SIP dialog 421aadbd3997bb1061fe41d23aca4d48@201.217.134.244:5060
[May 23 18:57:35] DEBUG[14921] chan_sip.c: = Looking for  Call ID: YzNjZjFhOWNjNzA1MWI3N2RjNmEzNjRjNGVlY2JlYjA. (Checking From) --From tag e4484a15 --To-tag   
[May 23 18:57:35] DEBUG[14921] logger.c: CALL_ID [C-0000006e] created by thread.
[May 23 18:57:35] DEBUG[14921] acl.c: For destination '192.168.1.54', our source address is '192.168.1.238'.
[May 23 18:57:35] DEBUG[14921] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.1.238:5060
[May 23 18:57:35] DEBUG[14921] chan_sip.c: Allocating new SIP dialog for YzNjZjFhOWNjNzA1MWI3N2RjNmEzNjRjNGVlY2JlYjA. - INVITE (No RTP)
[May 23 18:57:35] DEBUG[14921][C-0000006e] logger.c: CALL_ID [C-0000006e] bound to thread.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: Splitting '192.168.1.54:56916' into...
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: ...host '192.168.1.54' and port '56916'.
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.1.54:56916
[May 23 18:57:35] DEBUG[14921][C-0000006e] logger.c: Call_ID [C-0000006e] being removed from thread.
[May 23 18:57:35] DEBUG[14921] chan_sip.c: = Looking for  Call ID: YzNjZjFhOWNjNzA1MWI3N2RjNmEzNjRjNGVlY2JlYjA. (Checking From) --From tag e4484a15 --To-tag as2a57a51e  
[May 23 18:57:35] DEBUG[14921][C-0000006e] logger.c: CALL_ID [C-0000006e] bound to thread.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Stopping retransmission on 'YzNjZjFhOWNjNzA1MWI3N2RjNmEzNjRjNGVlY2JlYjA.' of Response 1: Match Found
[May 23 18:57:35] DEBUG[14921][C-0000006e] logger.c: Call_ID [C-0000006e] being removed from thread.
[May 23 18:57:35] DEBUG[14921] chan_sip.c: = Looking for  Call ID: YzNjZjFhOWNjNzA1MWI3N2RjNmEzNjRjNGVlY2JlYjA. (Checking From) --From tag e4484a15 --To-tag   
[May 23 18:57:35] DEBUG[14921] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:35] DEBUG[14921] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:35] DEBUG[14921] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:35] DEBUG[14921] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:35] DEBUG[14921][C-0000006e] logger.c: CALL_ID [C-0000006e] bound to thread.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: Splitting '192.168.1.54:56916' into...
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: ...host '192.168.1.54' and port '56916'.
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:35] DEBUG[14921][C-0000006e] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fef640793d8'
[May 23 18:57:35] DEBUG[14921][C-0000006e] res_rtp_asterisk.c: Allocated port 11806 for RTP instance '0x7fef640793d8'
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: Splitting '201.217.134.244' into...
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: ...host '201.217.134.244' and port ''.
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: Splitting '200.40.166.162' into...
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: ...host '200.40.166.162' and port ''.
[May 23 18:57:35] DEBUG[14921][C-0000006e] rtp_engine.c: RTP instance '0x7fef640793d8' is setup and ready to go
[May 23 18:57:35] DEBUG[14921][C-0000006e] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fef640793d8'
[May 23 18:57:35] VERBOSE[14921][C-0000006e] netsock2.c:   == Using SIP RTP CoS mark 5
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Setting NAT on RTP to Off
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing session-level SDP o=- 7 2 IN IP4 192.168.1.54... OK.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing session-level SDP s=CounterPath eyeBeam 1.5... UNSUPPORTED OR FAILED.
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: Splitting '192.168.1.54' into...
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: ...host '192.168.1.54' and port ''.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.1.54... OK.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[May 23 18:57:35] DEBUG[14921][C-0000006e] rtp_engine.c: Setting payload 0 based on m type on 0x7fef6b513cf0
[May 23 18:57:35] DEBUG[14921][C-0000006e] rtp_engine.c: Setting payload 8 based on m type on 0x7fef6b513cf0
[May 23 18:57:35] DEBUG[14921][C-0000006e] rtp_engine.c: Setting payload 18 based on m type on 0x7fef6b513cf0
[May 23 18:57:35] DEBUG[14921][C-0000006e] rtp_engine.c: Setting payload 101 based on m type on 0x7fef6b513cf0
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing media-level (audio) SDP a=alt:1 2 : dVat2PTD TEaTpR2W 192.168.1.54 23196... UNSUPPORTED OR FAILED.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing media-level (audio) SDP a=alt:2 1 : Kt44h+t6 q/dQtbv3 192.168.21.102 23196... UNSUPPORTED OR FAILED.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=yes... OK.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK.
[May 23 18:57:35] DEBUG[14921][C-0000006e] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fef640793d8'
[May 23 18:57:35] DEBUG[14921][C-0000006e] rtp_engine.c: Copying payload 0 from 0x7fef6b513cf0 to 0x7fef640795a0
[May 23 18:57:35] DEBUG[14921][C-0000006e] rtp_engine.c: Copying payload 8 from 0x7fef6b513cf0 to 0x7fef640795a0
[May 23 18:57:35] DEBUG[14921][C-0000006e] rtp_engine.c: Copying payload 18 from 0x7fef6b513cf0 to 0x7fef640795a0
[May 23 18:57:35] DEBUG[14921][C-0000006e] rtp_engine.c: Copying payload 101 from 0x7fef6b513cf0 to 0x7fef640795a0
[May 23 18:57:35] DEBUG[14921][C-0000006e] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fef640793d8'
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: We're settling with these formats: (ulaw|alaw|g729)
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Checking SIP call limits for device 4309
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Updating call counter for incoming call
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:35] DEBUG[14921][C-0000006e] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: *** Our native formats are (g729) 
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: *** Joint capabilities are (ulaw|alaw|g729) 
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: *** Our capabilities are (ulaw|alaw|g729) 
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: *** AST_CODEC_CHOOSE formats are g729 
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: This channel will not be able to handle video.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: build_route: Contact hop: <sip:4309@192.168.1.54:56916>
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: SIP/4309-000000dc: New call is still down.... Trying... 
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.1.54:56916
[May 23 18:57:35] DEBUG[14912] devicestate.c: No provider found, checking channel drivers for SIP - 4309
[May 23 18:57:35] DEBUG[14912] chan_sip.c: Checking device state for peer 4309
[May 23 18:57:35] DEBUG[14912] devicestate.c: Changing state for SIP/4309 - state 1 (Not in use)
[May 23 18:57:35] DEBUG[14912] devicestate.c: device 'SIP/4309' state '1'
[May 23 18:57:35] DEBUG[14921][C-0000006e] logger.c: Call_ID [C-0000006e] being removed from thread.
[May 23 18:57:35] DEBUG[14938] app_queue.c: Device 'SIP/4309' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[May 23 18:57:35] DEBUG[31373][C-0000006e] logger.c: CALL_ID [C-0000006e] bound to thread.
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Function result is '4309'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Result of 'EXTEN' is '959898999999'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Launching 'NoOp'
[May 23 18:57:35] VERBOSE[31373][C-0000006e] pbx.c:     -- Executing [959898999999@internos:1] NoOp("SIP/4309-000000dc", "LLamada Saliente desde 4309 a 59898999999") in new stack
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Result of 'EXTEN' is '959898999999'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Launching 'Goto'
[May 23 18:57:35] VERBOSE[31373][C-0000006e] pbx.c:     -- Executing [959898999999@internos:2] Goto("SIP/4309-000000dc", "paises,59898999999,1") in new stack
[May 23 18:57:35] VERBOSE[31373][C-0000006e] pbx.c:     -- Goto (paises,59898999999,1)
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Result of 'EXTEN' is '59898999999'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Function result is '4309'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Launching 'NoOp'
[May 23 18:57:35] VERBOSE[31373][C-0000006e] pbx.c:     -- Executing [59898999999@paises:1] NoOp("SIP/4309-000000dc", "Llamada a Uruguay 59898999999 desde 4309") in new stack
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Result of 'EXTEN' is '59898999999'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Result of 'EXTEN' is '59898999999'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Launching 'Macro'
[May 23 18:57:35] VERBOSE[31373][C-0000006e] pbx.c:     -- Executing [59898999999@paises:2] Macro("SIP/4309-000000dc", "failover-outbound,249098999999,pbxtelecom,59898999999,flowroute") in new stack
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Launching 'NoOp'
[May 23 18:57:35] VERBOSE[31373][C-0000006e] pbx.c:     -- Executing [s@macro-failover-outbound:1] NoOp("SIP/4309-000000dc", "Outbound with failover") in new stack
[May 23 18:57:35] DEBUG[31373][C-0000006e] app_macro.c: Executed application: Noop
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Result of 'EPOCH' is '1369346255'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Function result is '1305231857'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Function result is '4309'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Result of 'MACRO_EXTEN' is '59898999999'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Launching 'Set'
[May 23 18:57:35] VERBOSE[31373][C-0000006e] pbx.c:     -- Executing [s@macro-failover-outbound:2] Set("SIP/4309-000000dc", "FileName=1305231857-4309-59898999999") in new stack
[May 23 18:57:35] DEBUG[31373][C-0000006e] app_macro.c: Executed application: Set
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Result of 'ARG2' is 'pbxtelecom'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Result of 'ARG1' is '249098999999'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Result of 'FileName' is '1305231857-4309-59898999999'
[May 23 18:57:35] DEBUG[31373][C-0000006e] pbx.c: Launching 'Dial'
[May 23 18:57:35] VERBOSE[31373][C-0000006e] pbx.c:     -- Executing [s@macro-failover-outbound:3] Dial("SIP/4309-000000dc", "SIP/pbxtelecom/249098999999,,M(iniciar-grabacion,1305231857-4309-59898999999)g") in new stack
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: Asked to create a SIP channel with formats: (g729)
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: Allocating new SIP dialog for 3d49655a7428d0d379d2a59a4092f336@192.168.1.233:5060 - INVITE (No RTP)
[May 23 18:57:35] DEBUG[31373][C-0000006e] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fef64127f88'
[May 23 18:57:35] DEBUG[31373][C-0000006e] res_rtp_asterisk.c: Allocated port 13814 for RTP instance '0x7fef64127f88'
[May 23 18:57:35] DEBUG[31373][C-0000006e] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:35] DEBUG[31373][C-0000006e] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:35] DEBUG[31373][C-0000006e] netsock2.c: Splitting '201.217.134.244' into...
[May 23 18:57:35] DEBUG[31373][C-0000006e] netsock2.c: ...host '201.217.134.244' and port ''.
[May 23 18:57:35] DEBUG[31373][C-0000006e] netsock2.c: Splitting '200.40.166.162' into...
[May 23 18:57:35] DEBUG[31373][C-0000006e] netsock2.c: ...host '200.40.166.162' and port ''.
[May 23 18:57:35] DEBUG[31373][C-0000006e] rtp_engine.c: RTP instance '0x7fef64127f88' is setup and ready to go
[May 23 18:57:35] DEBUG[31373][C-0000006e] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fef64127f88'
[May 23 18:57:35] VERBOSE[31373][C-0000006e] netsock2.c:   == Using SIP RTP CoS mark 5
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: Setting NAT on RTP to Off
[May 23 18:57:35] DEBUG[31373][C-0000006e] acl.c: For destination '192.168.1.243', our source address is '192.168.1.238'.
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.1.238:5060
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: *** Our native formats are (g729) 
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: *** Joint capabilities are (g729) 
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: *** Our capabilities are (ulaw|g729) 
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: *** AST_CODEC_CHOOSE formats are g729 
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: *** Our preferred formats from the incoming channel are (g729) 
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: This channel will not be able to handle video.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel_internal_api.c: Channel Call ID changing from [C-0000006e] to [C-0000006e]
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable DIALEDTIME.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable ANSWEREDTIME.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable DIALEDPEERNAME.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable DIALEDPEERNUMBER.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable DIALSTATUS.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable MACRO_DEPTH.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable FileName.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable ARG4.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable ARG3.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable ARG2.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable ARG1.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable MACRO_PRIORITY.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable MACRO_CONTEXT.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable MACRO_EXTEN.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable SIPCALLID.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable SIPDOMAIN.
[May 23 18:57:35] DEBUG[31373][C-0000006e] channel.c: Not copying variable SIPURI.
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: Outgoing Call for 249098999999
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: Updating call counter for outgoing call
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: ** Our capability: (ulaw|g729) Video flag: False Text flag: False
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: ** Our prefcodec: (g729) 
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: -- Done with adding codecs to SDP
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|g729)
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: Initializing initreq for method INVITE - callid 6e1ec26f788bf85e385fd5ab449d9ad0@192.168.1.238:5060
[May 23 18:57:35] DEBUG[31373][C-0000006e] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.1.243:5060
[May 23 18:57:35] VERBOSE[31373][C-0000006e] app_dial.c:     -- Called SIP/pbxtelecom/249098999999
[May 23 18:57:35] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 6e1ec26f788bf85e385fd5ab449d9ad0@192.168.1.238:5060 (Checking To) --From tag as098971ed --To-tag   
[May 23 18:57:35] DEBUG[14921][C-0000006e] logger.c: CALL_ID [C-0000006e] bound to thread.
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6e1ec26f788bf85e385fd5ab449d9ad0@192.168.1.238:5060' Request 102: Found
[May 23 18:57:35] DEBUG[14921][C-0000006e] chan_sip.c: SIP response 100 to standard invite
[May 23 18:57:35] DEBUG[14921][C-0000006e] logger.c: Call_ID [C-0000006e] being removed from thread.
[May 23 18:57:36] DEBUG[14921] chan_sip.c: Allocating new SIP dialog for 4f9d7eae7c410302062dadd035120404@192.168.1.233:5060 - OPTIONS (No RTP)
[May 23 18:57:36] DEBUG[14921] acl.c: For destination '10.0.10.21', our source address is '192.168.1.238'.
[May 23 18:57:36] DEBUG[14921] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.1.238:5060
[May 23 18:57:36] DEBUG[14921] chan_sip.c: Initializing initreq for method OPTIONS - callid 16f8f41657014e2b61360f6b6523df4c@192.168.1.238:5060
[May 23 18:57:36] DEBUG[14921] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 10.0.10.21:5060
[May 23 18:57:36] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 16f8f41657014e2b61360f6b6523df4c@192.168.1.238:5060 (Checking To) --From tag as6e89c9ea --To-tag 2D7B8D5B-37445FC6  
[May 23 18:57:36] DEBUG[14921] chan_sip.c: Stopping retransmission on '16f8f41657014e2b61360f6b6523df4c@192.168.1.238:5060' of Request 102: Match Found
[May 23 18:57:36] DEBUG[14921] chan_sip.c: Destroying SIP dialog 16f8f41657014e2b61360f6b6523df4c@192.168.1.238:5060
[May 23 18:57:36] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 1ea9bb6b3f86f26b0c87817d2df8fe7f@199.189.87.30 (Checking From) --From tag as5b516c78 --To-tag   
[May 23 18:57:36] DEBUG[14921] acl.c: For destination '199.189.87.30', our source address is '201.217.134.244'.
[May 23 18:57:36] DEBUG[14921] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 201.217.134.244:5060
[May 23 18:57:36] DEBUG[14921] chan_sip.c: Allocating new SIP dialog for 1ea9bb6b3f86f26b0c87817d2df8fe7f@199.189.87.30 - OPTIONS (No RTP)
[May 23 18:57:36] DEBUG[14921] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS
[May 23 18:57:36] DEBUG[14921] netsock2.c: Splitting '201.217.134.244' into...
[May 23 18:57:36] DEBUG[14921] netsock2.c: ...host '201.217.134.244' and port ''.
[May 23 18:57:36] DEBUG[14921] netsock2.c: Splitting '199.189.87.30' into...
[May 23 18:57:36] DEBUG[14921] netsock2.c: ...host '199.189.87.30' and port ''.
[May 23 18:57:36] DEBUG[14921] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 199.189.87.30:5060
[May 23 18:57:39] DEBUG[14921] chan_sip.c: Allocating new SIP dialog for 1f356746404fbaa30c7639175f8a1201@192.168.1.233:5060 - OPTIONS (No RTP)
[May 23 18:57:39] DEBUG[14921] acl.c: For destination '95.211.119.240', our source address is '200.40.166.162'.
[May 23 18:57:39] DEBUG[14921] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 200.40.166.162:5060
[May 23 18:57:39] DEBUG[14921] chan_sip.c: Initializing initreq for method OPTIONS - callid 57e8668e5cdf07024ddfe4014290379e@200.40.166.162:5060
[May 23 18:57:39] DEBUG[14921] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 95.211.119.240:5060
[May 23 18:57:39] DEBUG[14921] chan_sip.c: Auto destroying SIP dialog '75b8cf8755ca0c877328d2cc16f94231@192.168.1.249'
[May 23 18:57:39] DEBUG[14921] chan_sip.c: Destroying SIP dialog 75b8cf8755ca0c877328d2cc16f94231@192.168.1.249
[May 23 18:57:39] DEBUG[14921] chan_sip.c: = Looking for  Call ID: YzNjZjFhOWNjNzA1MWI3N2RjNmEzNjRjNGVlY2JlYjA. (Checking From) --From tag e4484a15 --To-tag   
[May 23 18:57:39] DEBUG[14921] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:39] DEBUG[14921] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:39] DEBUG[14921] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:39] DEBUG[14921] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:39] DEBUG[14921][C-0000006e] logger.c: CALL_ID [C-0000006e] bound to thread.
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: **** Received CANCEL (14) - Command in SIP CANCEL
[May 23 18:57:39] DEBUG[14921][C-0000006e] netsock2.c: Splitting '192.168.1.54:56916' into...
[May 23 18:57:39] DEBUG[14921][C-0000006e] netsock2.c: ...host '192.168.1.54' and port '56916'.
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: Setting SIP_ALREADYGONE on dialog YzNjZjFhOWNjNzA1MWI3N2RjNmEzNjRjNGVlY2JlYjA.
[May 23 18:57:39] DEBUG[14921][C-0000006e] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fef640793d8'
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: Trying to put 'SIP/2.0 487' onto UDP socket destined for 192.168.1.54:56916
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.1.54:56916
[May 23 18:57:39] DEBUG[14921][C-0000006e] logger.c: Call_ID [C-0000006e] being removed from thread.
[May 23 18:57:39] DEBUG[31373][C-0000006e] channel.c: Hanging up channel 'SIP/pbxtelecom-000000dd'
[May 23 18:57:39] DEBUG[31373][C-0000006e] chan_sip.c: Hangup call SIP/pbxtelecom-000000dd, SIP callid 6e1ec26f788bf85e385fd5ab449d9ad0@192.168.1.238:5060
[May 23 18:57:39] DEBUG[31373][C-0000006e] chan_sip.c: Hanging up channel in state Down (not UP)
[May 23 18:57:39] DEBUG[31373][C-0000006e] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fef64127f88'
[May 23 18:57:39] DEBUG[31373][C-0000006e] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6e1ec26f788bf85e385fd5ab449d9ad0@192.168.1.238:5060' Request 102: Found
[May 23 18:57:39] DEBUG[31373][C-0000006e] chan_sip.c: Trying to put 'CANCEL sip:' onto UDP socket destined for 192.168.1.243:5060
[May 23 18:57:39] DEBUG[14912] devicestate.c: No provider found, checking channel drivers for SIP - pbxtelecom
[May 23 18:57:39] DEBUG[31373][C-0000006e] app_dial.c: Exiting with DIALSTATUS=CANCEL.
[May 23 18:57:39] DEBUG[14912] chan_sip.c: Checking device state for peer pbxtelecom
[May 23 18:57:39] DEBUG[31373][C-0000006e] app_macro.c: Spawn extension (macro-failover-outbound,s,3) exited non-zero on 'SIP/4309-000000dc' in macro 'failover-outbound'
[May 23 18:57:39] DEBUG[14912] devicestate.c: Changing state for SIP/pbxtelecom - state 1 (Not in use)
[May 23 18:57:39] VERBOSE[31373][C-0000006e] app_macro.c:   == Spawn extension (macro-failover-outbound, s, 3) exited non-zero on 'SIP/4309-000000dc' in macro 'failover-outbound'
[May 23 18:57:39] DEBUG[14912] devicestate.c: device 'SIP/pbxtelecom' state '1'
[May 23 18:57:39] DEBUG[31373][C-0000006e] pbx.c: Spawn extension (paises,59898999999,2) exited non-zero on 'SIP/4309-000000dc'
[May 23 18:57:39] VERBOSE[31373][C-0000006e] pbx.c:   == Spawn extension (paises, 59898999999, 2) exited non-zero on 'SIP/4309-000000dc'
[May 23 18:57:39] DEBUG[31373][C-0000006e] channel.c: Soft-Hanging up channel 'SIP/4309-000000dc'
[May 23 18:57:39] DEBUG[14938] app_queue.c: Device 'SIP/pbxtelecom' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[May 23 18:57:39] DEBUG[31373][C-0000006e] channel.c: Soft-Hanging up channel 'SIP/4309-000000dc'
[May 23 18:57:39] DEBUG[31373][C-0000006e] pbx.c: Launching 'NoOp'
[May 23 18:57:39] VERBOSE[31373][C-0000006e] pbx.c:     -- Executing [h@paises:1] NoOp("SIP/4309-000000dc", "Hang Up llamada saliente") in new stack
[May 23 18:57:39] DEBUG[31373][C-0000006e] pbx.c: Result of 'DIALSTATUS' is 'CANCEL'
[May 23 18:57:39] DEBUG[31373][C-0000006e] pbx.c: Expression result is '0'
[May 23 18:57:39] DEBUG[31373][C-0000006e] pbx.c: Launching 'GotoIf'
[May 23 18:57:39] VERBOSE[31373][C-0000006e] pbx.c:     -- Executing [h@paises:2] GotoIf("SIP/4309-000000dc", "0?contesto:fin") in new stack
[May 23 18:57:39] VERBOSE[31373][C-0000006e] pbx.c:     -- Goto (paises,h,6)
[May 23 18:57:39] DEBUG[31373][C-0000006e] pbx.c: Result of 'FileName' is '1305231857-4309-59898999999'
[May 23 18:57:39] DEBUG[31373][C-0000006e] pbx.c: Launching 'System'
[May 23 18:57:39] VERBOSE[31373][C-0000006e] pbx.c:     -- Executing [h@paises:6] System("SIP/4309-000000dc", "rm /var/spool/asterisk/monitor/1305231857-4309-59898999999.wav") in new stack
[May 23 18:57:39] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 6e1ec26f788bf85e385fd5ab449d9ad0@192.168.1.238:5060 (Checking To) --From tag as098971ed --To-tag as5d3fb207  
[May 23 18:57:39] DEBUG[14921][C-0000006e] logger.c: CALL_ID [C-0000006e] bound to thread.
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: Acked pending invite 102
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: Stopping retransmission on '6e1ec26f788bf85e385fd5ab449d9ad0@192.168.1.238:5060' of Request 102: Match Found
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: SIP response 487 to standard invite
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: Trying to put 'ACK sip:249' onto UDP socket destined for 192.168.1.243:5060
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: Updating call counter for outgoing call
[May 23 18:57:39] DEBUG[14921][C-0000006e] logger.c: Call_ID [C-0000006e] being removed from thread.
[May 23 18:57:39] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 6e1ec26f788bf85e385fd5ab449d9ad0@192.168.1.238:5060 (Checking To) --From tag as098971ed --To-tag as5d3fb207  
[May 23 18:57:39] DEBUG[14921][C-0000006e] logger.c: CALL_ID [C-0000006e] bound to thread.
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: Stopping retransmission on '6e1ec26f788bf85e385fd5ab449d9ad0@192.168.1.238:5060' of Request 102: Match Found
[May 23 18:57:39] DEBUG[14921][C-0000006e] logger.c: Call_ID [C-0000006e] being removed from thread.
[May 23 18:57:39] DEBUG[31373][C-0000006e] pbx.c: Launching 'Hangup'
[May 23 18:57:39] VERBOSE[31373][C-0000006e] pbx.c:     -- Executing [h@paises:7] Hangup("SIP/4309-000000dc", "") in new stack
[May 23 18:57:39] DEBUG[31373][C-0000006e] channel.c: Soft-Hanging up channel 'SIP/4309-000000dc'
[May 23 18:57:39] DEBUG[31373][C-0000006e] pbx.c: Spawn extension (paises,h,7) exited non-zero on 'SIP/4309-000000dc'
[May 23 18:57:39] VERBOSE[31373][C-0000006e] pbx.c:   == Spawn extension (paises, h, 7) exited non-zero on 'SIP/4309-000000dc'
[May 23 18:57:39] DEBUG[31373][C-0000006e] channel.c: Hanging up channel 'SIP/4309-000000dc'
[May 23 18:57:39] DEBUG[31373][C-0000006e] chan_sip.c: Hangup call SIP/4309-000000dc, SIP callid YzNjZjFhOWNjNzA1MWI3N2RjNmEzNjRjNGVlY2JlYjA.
[May 23 18:57:39] DEBUG[31373][C-0000006e] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fef640793d8'
[May 23 18:57:39] WARNING[31373][C-0000006e] res_odbc.c: SQL Execute error! Verifying connection to local [MySQL-Local]...
[May 23 18:57:39] ERROR[31373][C-0000006e] cdr_odbc.c: CDR direct execute failed
[May 23 18:57:39] DEBUG[31373][C-0000006e] res_odbc.c: odbc_release_obj2(0x7fef88033f48) called (obj->txf = (nil))
[May 23 18:57:39] DEBUG[14912] devicestate.c: No provider found, checking channel drivers for SIP - 4309
[May 23 18:57:39] DEBUG[14912] chan_sip.c: Checking device state for peer 4309
[May 23 18:57:39] DEBUG[14912] devicestate.c: Changing state for SIP/4309 - state 1 (Not in use)
[May 23 18:57:39] DEBUG[14912] devicestate.c: device 'SIP/4309' state '1'
[May 23 18:57:39] DEBUG[14938] app_queue.c: Device 'SIP/4309' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[May 23 18:57:39] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 57e8668e5cdf07024ddfe4014290379e@200.40.166.162:5060 (Checking To) --From tag as10b60675 --To-tag 975eb251270ab81705c4ea3580c95c85.f7b0  
[May 23 18:57:39] DEBUG[14921] chan_sip.c: Stopping retransmission on '57e8668e5cdf07024ddfe4014290379e@200.40.166.162:5060' of Request 102: Match Found
[May 23 18:57:39] DEBUG[14921] chan_sip.c: Destroying SIP dialog 57e8668e5cdf07024ddfe4014290379e@200.40.166.162:5060
[May 23 18:57:39] DEBUG[14921] chan_sip.c: = Looking for  Call ID: YzNjZjFhOWNjNzA1MWI3N2RjNmEzNjRjNGVlY2JlYjA. (Checking From) --From tag e4484a15 --To-tag as41c5828d  
[May 23 18:57:39] DEBUG[14921][C-0000006e] logger.c: CALL_ID [C-0000006e] bound to thread.
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[May 23 18:57:39] DEBUG[14921][C-0000006e] chan_sip.c: Stopping retransmission on 'YzNjZjFhOWNjNzA1MWI3N2RjNmEzNjRjNGVlY2JlYjA.' of Response 2: Match Found
[May 23 18:57:39] DEBUG[14921][C-0000006e] logger.c: Call_ID [C-0000006e] being removed from thread.
[May 23 18:57:39] DEBUG[14921] chan_sip.c: Destroying SIP dialog YzNjZjFhOWNjNzA1MWI3N2RjNmEzNjRjNGVlY2JlYjA.
[May 23 18:57:39] DEBUG[14921] rtp_engine.c: Destroyed RTP instance '0x7fef640793d8'
[May 23 18:57:41] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 6494408d-6447bf37-b9647c58@10.0.10.15 (Checking From) --From tag DF13E31-11FD43DA --To-tag   
[May 23 18:57:41] DEBUG[14921] acl.c: For destination '10.0.10.15', our source address is '192.168.1.238'.
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.1.238:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Allocating new SIP dialog for 6494408d-6447bf37-b9647c58@10.0.10.15 - REGISTER (No RTP)
[May 23 18:57:41] DEBUG[14921] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[May 23 18:57:41] DEBUG[14921] netsock2.c: Splitting '10.0.10.15' into...
[May 23 18:57:41] DEBUG[14921] netsock2.c: ...host '10.0.10.15' and port ''.
[May 23 18:57:41] DEBUG[14921] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:41] DEBUG[14921] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.0.10.15:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 6494408d-6447bf37-b9647c58@10.0.10.15 (Checking From) --From tag DF13E31-11FD43DA --To-tag   
[May 23 18:57:41] DEBUG[14921] netsock2.c: Splitting '192.168.1.238:5060' into...
[May 23 18:57:41] DEBUG[14921] netsock2.c: ...host '192.168.1.238' and port '5060'.
[May 23 18:57:41] DEBUG[14921] netsock2.c: Splitting '192.168.1.238:5060' into...
[May 23 18:57:41] DEBUG[14921] netsock2.c: ...host '192.168.1.238' and port '5060'.
[May 23 18:57:41] DEBUG[14921] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[May 23 18:57:41] DEBUG[14921] netsock2.c: Splitting '10.0.10.15' into...
[May 23 18:57:41] DEBUG[14921] netsock2.c: ...host '10.0.10.15' and port ''.
[May 23 18:57:41] DEBUG[14921] netsock2.c: Splitting '192.168.1.238' into...
[May 23 18:57:41] DEBUG[14921] netsock2.c: ...host '192.168.1.238' and port ''.
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Store REGISTER's Contact header for call routing.
[May 23 18:57:41] DEBUG[14921] netsock2.c: Splitting '10.0.10.15' into...
[May 23 18:57:41] DEBUG[14921] netsock2.c: ...host '10.0.10.15' and port ''.
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Allocating new SIP dialog for 02eb25ac049f880c56c271cd07b108dd@192.168.1.233:5060 - OPTIONS (No RTP)
[May 23 18:57:41] DEBUG[14921] acl.c: For destination '10.0.10.15', our source address is '192.168.1.238'.
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.1.238:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Initializing initreq for method OPTIONS - callid 589431ab4ead44d64298a7131fdbbf1b@192.168.1.238:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 10.0.10.15:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.0.10.15:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Allocating new SIP dialog for 70ed5754766cd9fc2d46b872418785c9@192.168.1.233:5060 - NOTIFY (No RTP)
[May 23 18:57:41] DEBUG[14921] acl.c: For destination '10.0.10.15', our source address is '192.168.1.238'.
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.1.238:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Initializing initreq for method NOTIFY - callid 33df4d0a74606aa619d19dc96cce9dd9@192.168.1.238:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 10.0.10.15:5060
[May 23 18:57:41] DEBUG[14912] devicestate.c: No provider found, checking channel drivers for SIP - 4203
[May 23 18:57:41] DEBUG[14912] chan_sip.c: Checking device state for peer 4203
[May 23 18:57:41] DEBUG[14912] devicestate.c: Changing state for SIP/4203 - state 1 (Not in use)
[May 23 18:57:41] DEBUG[14912] devicestate.c: device 'SIP/4203' state '1'
[May 23 18:57:41] DEBUG[14938] app_queue.c: Device 'SIP/4203' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[May 23 18:57:41] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 589431ab4ead44d64298a7131fdbbf1b@192.168.1.238:5060 (Checking To) --From tag as6febd37a --To-tag 457505EB-2FE6631C  
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Stopping retransmission on '589431ab4ead44d64298a7131fdbbf1b@192.168.1.238:5060' of Request 102: Match Found
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Destroying SIP dialog 589431ab4ead44d64298a7131fdbbf1b@192.168.1.238:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 200 ms (t1 100 ms (Retrans id #162770)) 
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 10.0.10.15:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 33df4d0a74606aa619d19dc96cce9dd9@192.168.1.238:5060 (Checking To) --From tag as7e965e36 --To-tag 71160670-F1422085  
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Stopping retransmission on '33df4d0a74606aa619d19dc96cce9dd9@192.168.1.238:5060' of Request 102: Match Found
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Got 200 accepted on NOTIFY 33df4d0a74606aa619d19dc96cce9dd9@192.168.1.238:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Destroying SIP dialog 33df4d0a74606aa619d19dc96cce9dd9@192.168.1.238:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 33df4d0a74606aa619d19dc96cce9dd9@192.168.1.238:5060 (Checking To) --From tag as7e965e36 --To-tag 71160670-F1422085  
[May 23 18:57:41] DEBUG[14921] chan_sip.c: That's odd...  Got a response on a call we don't know about. Callid 33df4d0a74606aa619d19dc96cce9dd9@192.168.1.238:5060
[May 23 18:57:41] DEBUG[14921] chan_sip.c: Invalid SIP message - rejected , no callid, len 408
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Allocating new SIP dialog for 4deeadbf32967cfa28e55ca47beb1a42@192.168.1.233:5060 - OPTIONS (No RTP)
[May 23 18:57:45] DEBUG[14921] acl.c: For destination '10.0.10.26', our source address is '192.168.1.238'.
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.1.238:5060
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Initializing initreq for method OPTIONS - callid 2c4e130866f1ffea43d2d4ed77312cd0@192.168.1.238:5060
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 10.0.10.26:5060
[May 23 18:57:45] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 2c4e130866f1ffea43d2d4ed77312cd0@192.168.1.238:5060 (Checking To) --From tag as6d6a9694 --To-tag C11B0A7-F09FD3C  
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Stopping retransmission on '2c4e130866f1ffea43d2d4ed77312cd0@192.168.1.238:5060' of Request 102: Match Found
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Destroying SIP dialog 2c4e130866f1ffea43d2d4ed77312cd0@192.168.1.238:5060
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Allocating new SIP dialog for 1f0a097757236255764aba901d4d7c5e@192.168.1.233:5060 - OPTIONS (No RTP)
[May 23 18:57:45] DEBUG[14921] acl.c: For destination '10.0.10.89', our source address is '192.168.1.238'.
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.1.238:5060
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Initializing initreq for method OPTIONS - callid 39c88ab320bf70331153368c2079d86c@192.168.1.238:5060
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 10.0.10.89:5060
[May 23 18:57:45] DEBUG[14921] chan_sip.c: = Looking for  Call ID: 39c88ab320bf70331153368c2079d86c@192.168.1.238:5060 (Checking To) --From tag as688131f6 --To-tag 701C8FDD-CB25363C  
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Stopping retransmission on '39c88ab320bf70331153368c2079d86c@192.168.1.238:5060' of Request 102: Match Found
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Destroying SIP dialog 39c88ab320bf70331153368c2079d86c@192.168.1.238:5060
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Auto destroying SIP dialog '6e1ec26f788bf85e385fd5ab449d9ad0@192.168.1.238:5060'
[May 23 18:57:45] DEBUG[14921] chan_sip.c: Destroying SIP dialog 6e1ec26f788bf85e385fd5ab449d9ad0@192.168.1.238:5060
[May 23 18:57:45] DEBUG[14921] rtp_engine.c: Destroyed RTP instance '0x7fef64127f88'