[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: [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'