Jul 6 17:11:20 DEBUG[11759] chan_sip.c: Target address 213.148.136.2 is not local, substituting externip Jul 6 17:11:20 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for d860151fcaf0814bb12c591e31561eca@sx3000 - INVITE (With RTP) Jul 6 17:11:20 DEBUG[11759] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jul 6 17:11:20 DEBUG[11759] chan_sip.c: * SIP extension value: 2 for call d860151fcaf0814bb12c591e31561eca@sx3000 Jul 6 17:11:20 DEBUG[11759] chan_sip.c: Setting NAT on RTP to 524288 Jul 6 17:11:20 DEBUG[11759] chan_sip.c: Checking SIP call limits for device 06765765765 Jul 6 17:11:20 DEBUG[11759] chan_sip.c: Updating call counter for incoming call Jul 6 17:11:20 DEBUG[11759] chan_sip.c: build_route: Contact hop: Jul 6 17:11:20 DEBUG[11838] pbx.c: Launching 'Macro' Jul 6 17:11:20 VERBOSE[11838] logger.c: -- Executing Macro("SIP/06765765765-810e", "wirhabenfrei|qscin|06765765765") in new stack Jul 6 17:11:20 DEBUG[11838] pbx.c: Launching 'Ringing' Jul 6 17:11:20 VERBOSE[11838] logger.c: -- Executing Ringing("SIP/06765765765-810e", "") in new stack Jul 6 17:11:20 DEBUG[11748] chan_sip.c: Checking device state for peer 06765765765 Jul 6 17:11:20 DEBUG[11748] devicestate.c: Changing state for SIP/06765765765 - state 2 (In use) Jul 6 17:11:20 DEBUG[11838] pbx.c: Launching 'Wait' Jul 6 17:11:20 VERBOSE[11838] logger.c: -- Executing Wait("SIP/06765765765-810e", "4") in new stack Jul 6 17:11:20 DEBUG[11839] app_queue.c: Device 'SIP/06765765765' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'GotoIfTime' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing GotoIfTime("SIP/06765765765-810e", "*|sat-sun|*|*?15") in new stack Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'GotoIfTime' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing GotoIfTime("SIP/06765765765-810e", "*|*|1|jan?15") in new stack Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'GotoIfTime' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing GotoIfTime("SIP/06765765765-810e", "*|*|3|oct?15") in new stack Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'GotoIfTime' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing GotoIfTime("SIP/06765765765-810e", "*|*|24-26|dec?15") in new stack Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'GotoIfTime' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing GotoIfTime("SIP/06765765765-810e", "*|*|1|may?15") in new stack Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'GotoIfTime' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing GotoIfTime("SIP/06765765765-810e", "*|*|15|apr?15") in new stack Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'GotoIfTime' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing GotoIfTime("SIP/06765765765-810e", "*|*|17|apr?15") in new stack Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'GotoIfTime' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing GotoIfTime("SIP/06765765765-810e", "*|*|25|may?15") in new stack Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'GotoIfTime' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing GotoIfTime("SIP/06765765765-810e", "*|*|5|jun?15") in new stack Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'GotoIfTime' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing GotoIfTime("SIP/06765765765-810e", "18:00-10:00|*|*?15") in new stack Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'GotoIfTime' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing GotoIfTime("SIP/06765765765-810e", "*|*|30|dec?15") in new stack Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'Goto' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing Goto("SIP/06765765765-810e", "qscin|06765765765|8") in new stack Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Goto (qscin,06765765765,8) Jul 6 17:11:24 VERBOSE[11838] logger.c: == Channel 'SIP/06765765765-810e' jumping out of macro 'wirhabenfrei' Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'Answer' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing Answer("SIP/06765765765-810e", "") in new stack Jul 6 17:11:24 DEBUG[11838] chan_sip.c: sip_answer(SIP/06765765765-810e) Jul 6 17:11:24 DEBUG[11838] pbx.c: Launching 'Playback' Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Executing Playback("SIP/06765765765-810e", "custom/willkommen_rb24") in new stack Jul 6 17:11:24 DEBUG[11838] channel.c: Set channel SIP/06765765765-810e to write format slin Jul 6 17:11:24 DEBUG[11838] rtp.c: Ooh, format changed from unknown to alaw Jul 6 17:11:24 VERBOSE[11838] logger.c: -- Playing 'custom/willkommen_rb24' (language 'de') Jul 6 17:11:24 DEBUG[11748] chan_sip.c: Checking device state for peer 06765765765 Jul 6 17:11:24 DEBUG[11748] devicestate.c: Changing state for SIP/06765765765 - state 2 (In use) Jul 6 17:11:24 DEBUG[11840] app_queue.c: Device 'SIP/06765765765' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 6 17:11:24 DEBUG[11759] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jul 6 17:11:24 DEBUG[11759] chan_sip.c: Stopping retransmission on 'd860151fcaf0814bb12c591e31561eca@sx3000' of Response 1: Match Found Jul 6 17:11:29 DEBUG[11838] rtp.c: Got RTCP report of 84 bytes Jul 6 17:11:34 DEBUG[11838] rtp.c: Got RTCP report of 84 bytes Jul 6 17:11:36 DEBUG[11838] channel.c: Set channel SIP/06765765765-810e to write format alaw Jul 6 17:11:36 DEBUG[11838] pbx.c: Function result is 'anonymous' Jul 6 17:11:36 DEBUG[11838] pbx.c: Launching 'Set' Jul 6 17:11:36 VERBOSE[11838] logger.c: -- Executing Set("SIP/06765765765-810e", "CALLERID(all)=XXXX ") in new stack Jul 6 17:11:36 DEBUG[11838] pbx.c: Launching 'Queue' Jul 6 17:11:36 VERBOSE[11838] logger.c: -- Executing Queue("SIP/06765765765-810e", "qrb24|Tt") in new stack Jul 6 17:11:36 DEBUG[11838] app_queue.c: NO QUEUE_PRIO variable found. Using default. Jul 6 17:11:36 DEBUG[11838] app_queue.c: queue: qrb24, options: Tt, url: (null), announce: (null), expires: 0, priority: 0 Jul 6 17:11:36 DEBUG[11838] app_queue.c: Queue 'qrb24' Join, Channel 'SIP/06765765765-810e', Position '1' Jul 6 17:11:36 DEBUG[11838] channel.c: Set channel SIP/06765765765-810e to write format slin Jul 6 17:11:36 VERBOSE[11838] logger.c: -- Started music on hold, class 'default', on channel 'SIP/06765765765-810e' Jul 6 17:11:36 DEBUG[11838] app_queue.c: It's our turn (SIP/06765765765-810e). Jul 6 17:11:36 DEBUG[11838] app_queue.c: SIP/06765765765-810e is trying to call a queue member. Jul 6 17:11:36 DEBUG[11838] app_queue.c: Simple queue (no URL) Jul 6 17:11:36 DEBUG[11838] app_queue.c: Simple queue (no URL) Jul 6 17:11:36 DEBUG[11838] app_queue.c: Simple queue (no URL) Jul 6 17:11:36 DEBUG[11838] app_queue.c: (Parallel) Trying 'Agent/4462' with metric 0 Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-11. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-10. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable PLAYBACKSTATUS. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-9. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-8. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable MACRO_DEPTH. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-14. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-13. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-12. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-11. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-10. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-9. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-8. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-7. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-6. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-5. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-4. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-3. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-2. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-1. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-1. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable SIPCALLID. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable SIPDOMAIN. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable SIPURI. Jul 6 17:11:36 VERBOSE[11838] logger.c: -- outgoing agentcall, to agent '4462', on 'Local/4462@user-b43c,1' Jul 6 17:11:36 DEBUG[11841] pbx.c: Launching 'Dial' Jul 6 17:11:36 VERBOSE[11841] logger.c: -- Executing Dial("Local/4462@user-b43c,2", "SIP/4462|55|tTr") in new stack Jul 6 17:11:36 DEBUG[11841] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jul 6 17:11:36 DEBUG[11841] chan_sip.c: Setting NAT on RTP to 0 Jul 6 17:11:36 DEBUG[11841] acl.c: ##### Testing 192.168.0.61 with 192.168.0.0 Jul 6 17:11:36 DEBUG[11841] channel.c: Not copying variable STACK-user-4462-1. Jul 6 17:11:36 DEBUG[11841] chan_sip.c: Outgoing Call for 4462 Jul 6 17:11:36 DEBUG[11841] chan_sip.c: Updating call counter for outgoing call Jul 6 17:11:36 VERBOSE[11841] logger.c: -- Called 4462 Jul 6 17:11:36 VERBOSE[11838] logger.c: -- Called Agent/4462 Jul 6 17:11:36 DEBUG[11838] app_queue.c: (Parallel) Trying 'Agent/4461' with metric 0 Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-11. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-10. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable PLAYBACKSTATUS. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-9. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-8. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable MACRO_DEPTH. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-14. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-13. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-12. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-11. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-10. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-9. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-8. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-7. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-6. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-5. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-4. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-3. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-2. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-1. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-1. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable SIPCALLID. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable SIPDOMAIN. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable SIPURI. Jul 6 17:11:36 VERBOSE[11838] logger.c: -- outgoing agentcall, to agent '4461', on 'Local/4461@user-2fcf,1' Jul 6 17:11:36 DEBUG[11842] pbx.c: Launching 'Dial' Jul 6 17:11:36 VERBOSE[11842] logger.c: -- Executing Dial("Local/4461@user-2fcf,2", "SIP/4461|55|tTr") in new stack Jul 6 17:11:36 DEBUG[11842] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jul 6 17:11:36 DEBUG[11842] chan_sip.c: Setting NAT on RTP to 0 Jul 6 17:11:36 DEBUG[11842] acl.c: ##### Testing 192.168.0.58 with 192.168.0.0 Jul 6 17:11:36 DEBUG[11842] channel.c: Not copying variable STACK-user-4461-1. Jul 6 17:11:36 DEBUG[11842] chan_sip.c: Outgoing Call for 4461 Jul 6 17:11:36 DEBUG[11842] chan_sip.c: Updating call counter for outgoing call Jul 6 17:11:36 VERBOSE[11842] logger.c: -- Called 4461 Jul 6 17:11:36 VERBOSE[11838] logger.c: -- Called Agent/4461 Jul 6 17:11:36 DEBUG[11838] app_queue.c: (Parallel) Trying 'Agent/4460' with metric 0 Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-11. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-10. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable PLAYBACKSTATUS. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-9. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-8. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable MACRO_DEPTH. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-14. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-13. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-12. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-11. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-10. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-9. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-8. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-7. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-6. Jul 6 17:11:36 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4462@user-b43c,2' Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-5. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-4. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-3. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-2. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-macro-wirhabenfrei-s-1. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable STACK-qscin-06765765765-1. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable SIPCALLID. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable SIPDOMAIN. Jul 6 17:11:36 DEBUG[11838] channel.c: Not copying variable SIPURI. Jul 6 17:11:36 VERBOSE[11838] logger.c: -- outgoing agentcall, to agent '4460', on 'Local/4460@user-e18d,1' Jul 6 17:11:36 DEBUG[11843] pbx.c: Launching 'Dial' Jul 6 17:11:36 VERBOSE[11843] logger.c: -- Executing Dial("Local/4460@user-e18d,2", "SIP/4460|55|tTr") in new stack Jul 6 17:11:36 DEBUG[11748] devicestate.c: Changing state for Local/4462@user - state 2 (In use) Jul 6 17:11:36 DEBUG[11844] app_queue.c: Device 'Local/4462@user' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 6 17:11:36 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4461@user-2fcf,2' Jul 6 17:11:36 DEBUG[11843] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jul 6 17:11:36 DEBUG[11843] chan_sip.c: Setting NAT on RTP to 0 Jul 6 17:11:36 DEBUG[11843] acl.c: ##### Testing 192.168.0.60 with 192.168.0.0 Jul 6 17:11:36 DEBUG[11759] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '7530b2ae035dad71015f5cff041d8269@192.168.0.200' Request 102: Found Jul 6 17:11:36 DEBUG[11759] chan_sip.c: SIP response 100 to standard invite Jul 6 17:11:36 DEBUG[11843] channel.c: Not copying variable STACK-user-4460-1. Jul 6 17:11:36 DEBUG[11843] chan_sip.c: Outgoing Call for 4460 Jul 6 17:11:36 DEBUG[11843] chan_sip.c: Updating call counter for outgoing call Jul 6 17:11:36 VERBOSE[11843] logger.c: -- Called 4460 Jul 6 17:11:36 VERBOSE[11838] logger.c: -- Called Agent/4460 Jul 6 17:11:36 VERBOSE[11838] logger.c: -- Agent/4462 is ringing Jul 6 17:11:36 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4461@user-2fcf,2' Jul 6 17:11:36 VERBOSE[11838] logger.c: -- Agent/4461 is ringing Jul 6 17:11:36 VERBOSE[11838] logger.c: -- Agent/4460 is ringing Jul 6 17:11:36 DEBUG[11748] devicestate.c: Changing state for Local/4461@user - state 2 (In use) Jul 6 17:11:36 DEBUG[11759] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1c94d0935d57790c7499f0df1d64f8bb@192.168.0.200' Request 102: Found Jul 6 17:11:36 DEBUG[11759] chan_sip.c: SIP response 100 to standard invite Jul 6 17:11:36 DEBUG[11845] app_queue.c: Device 'Local/4461@user' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 6 17:11:36 DEBUG[11748] devicestate.c: Changing state for Local/4460@user - state 2 (In use) Jul 6 17:11:36 DEBUG[11846] app_queue.c: Device 'Local/4460@user' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 6 17:11:36 DEBUG[11759] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6ca057163f0507f2780b53ae7d8d4875@192.168.0.200' Request 102: Found Jul 6 17:11:36 DEBUG[11759] chan_sip.c: SIP response 100 to standard invite Jul 6 17:11:36 DEBUG[11759] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6ca057163f0507f2780b53ae7d8d4875@192.168.0.200' Request 102: Found Jul 6 17:11:36 DEBUG[11759] chan_sip.c: SIP response 180 to standard invite Jul 6 17:11:36 DEBUG[11748] chan_sip.c: Checking device state for peer 4460 Jul 6 17:11:36 VERBOSE[11843] logger.c: -- SIP/4460-8d74 is ringing Jul 6 17:11:36 DEBUG[11748] devicestate.c: Changing state for SIP/4460 - state 6 (Ringing) Jul 6 17:11:36 DEBUG[11847] app_queue.c: Device 'SIP/4460' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Jul 6 17:11:36 DEBUG[11759] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '7530b2ae035dad71015f5cff041d8269@192.168.0.200' Request 102: Found Jul 6 17:11:36 DEBUG[11759] chan_sip.c: SIP response 180 to standard invite Jul 6 17:11:36 VERBOSE[11841] logger.c: -- SIP/4462-72cf is ringing Jul 6 17:11:36 DEBUG[11748] chan_sip.c: Checking device state for peer 4462 Jul 6 17:11:36 DEBUG[11748] devicestate.c: Changing state for SIP/4462 - state 6 (Ringing) Jul 6 17:11:36 DEBUG[11848] app_queue.c: Device 'SIP/4462' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Jul 6 17:11:36 DEBUG[11759] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1c94d0935d57790c7499f0df1d64f8bb@192.168.0.200' Request 102: Found Jul 6 17:11:36 DEBUG[11759] chan_sip.c: SIP response 180 to standard invite Jul 6 17:11:36 VERBOSE[11842] logger.c: -- SIP/4461-587e is ringing Jul 6 17:11:36 DEBUG[11748] chan_sip.c: Checking device state for peer 4461 Jul 6 17:11:36 DEBUG[11748] devicestate.c: Changing state for SIP/4461 - state 6 (Ringing) Jul 6 17:11:36 DEBUG[11849] app_queue.c: Device 'SIP/4461' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11759] chan_sip.c: Acked pending invite 102 Jul 6 17:11:38 DEBUG[11759] chan_sip.c: Stopping retransmission on '1c94d0935d57790c7499f0df1d64f8bb@192.168.0.200' of Request 102: Match Found Jul 6 17:11:38 DEBUG[11759] chan_sip.c: SIP response 200 to standard invite Jul 6 17:11:38 DEBUG[11759] chan_sip.c: build_route: Contact hop: Jul 6 17:11:38 VERBOSE[11842] logger.c: -- SIP/4461-587e answered Local/4461@user-2fcf,2 Jul 6 17:11:38 DEBUG[11838] app_queue.c: Dunno what to do with control type -1 Jul 6 17:11:38 DEBUG[11842] channel.c: Set channel Local/4461@user-2fcf,2 to read format alaw Jul 6 17:11:38 DEBUG[11842] channel.c: Set channel SIP/4461-587e to write format alaw Jul 6 17:11:38 DEBUG[11842] channel.c: Set channel SIP/4461-587e to read format alaw Jul 6 17:11:38 DEBUG[11842] channel.c: Set channel Local/4461@user-2fcf,2 to write format alaw Jul 6 17:11:38 VERBOSE[11838] logger.c: -- Agent/4461 answered SIP/06765765765-810e Jul 6 17:11:38 DEBUG[11838] channel.c: Hanging up channel 'Agent/4462' Jul 6 17:11:38 DEBUG[11838] chan_agent.c: Hangup called for state Down Jul 6 17:11:38 DEBUG[11838] channel.c: Hanging up channel 'Local/4462@user-b43c,1' Jul 6 17:11:38 DEBUG[11838] chan_agent.c: Hungup, howlong is 2, autologoff is 0 Jul 6 17:11:38 DEBUG[11838] channel.c: Hanging up channel 'Agent/4460' Jul 6 17:11:38 DEBUG[11838] chan_agent.c: Hangup called for state Down Jul 6 17:11:38 DEBUG[11838] channel.c: Hanging up channel 'Local/4460@user-e18d,1' Jul 6 17:11:38 DEBUG[11838] chan_agent.c: Hungup, howlong is 2, autologoff is 0 Jul 6 17:11:38 DEBUG[11838] channel.c: Set channel Agent/4461 to write format gsm Jul 6 17:11:38 DEBUG[11841] channel.c: Hanging up channel 'SIP/4462-72cf' Jul 6 17:11:38 DEBUG[11841] chan_sip.c: Hangup call SIP/4462-72cf, SIP callid 7530b2ae035dad71015f5cff041d8269@192.168.0.200) Jul 6 17:11:38 DEBUG[11841] chan_sip.c: update_call_counter(4462) - decrement call limit counter Jul 6 17:11:38 DEBUG[11841] chan_sip.c: Updating call counter for outgoing call Jul 6 17:11:38 DEBUG[11841] chan_sip.c: Acked pending invite 102 Jul 6 17:11:38 DEBUG[11841] chan_sip.c: Stopping retransmission on '7530b2ae035dad71015f5cff041d8269@192.168.0.200' of Request 102: Match Found Jul 6 17:11:38 DEBUG[11843] channel.c: Hanging up channel 'SIP/4460-8d74' Jul 6 17:11:38 DEBUG[11843] chan_sip.c: Hangup call SIP/4460-8d74, SIP callid 6ca057163f0507f2780b53ae7d8d4875@192.168.0.200) Jul 6 17:11:38 DEBUG[11843] chan_sip.c: update_call_counter(4460) - decrement call limit counter Jul 6 17:11:38 DEBUG[11843] chan_sip.c: Updating call counter for outgoing call Jul 6 17:11:38 DEBUG[11843] chan_sip.c: Acked pending invite 102 Jul 6 17:11:38 DEBUG[11843] chan_sip.c: Stopping retransmission on '6ca057163f0507f2780b53ae7d8d4875@192.168.0.200' of Request 102: Match Found Jul 6 17:11:38 VERBOSE[11838] logger.c: -- Playing 'custom/rb24' (language 'en') Jul 6 17:11:38 DEBUG[11841] app_dial.c: Exiting with DIALSTATUS=CANCEL. Jul 6 17:11:38 DEBUG[11841] pbx.c: Spawn extension (user,4462,1) exited non-zero on 'Local/4462@user-b43c,2' Jul 6 17:11:38 DEBUG[11748] chan_sip.c: Checking device state for peer 4461 Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for SIP/4461 - state 2 (In use) Jul 6 17:11:38 DEBUG[11850] app_queue.c: Device 'SIP/4461' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Local/4461@user - state 2 (In use) Jul 6 17:11:38 DEBUG[11851] app_queue.c: Device 'Local/4461@user' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Agent/4461 - state 3 (Busy) Jul 6 17:11:38 DEBUG[11852] app_queue.c: Device 'Agent/4461' changed to state '3' (Busy) Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4462@user-b43c,2' Jul 6 17:11:38 DEBUG[11842] rtp.c: Ooh, format changed from unknown to alaw Jul 6 17:11:38 DEBUG[11843] app_dial.c: Exiting with DIALSTATUS=CANCEL. Jul 6 17:11:38 DEBUG[11843] pbx.c: Spawn extension (user,4460,1) exited non-zero on 'Local/4460@user-e18d,2' Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4462@user-b43c,2' Jul 6 17:11:38 DEBUG[11842] channel.c: Planning to masquerade channel SIP/4461-587e into the structure of Local/4461@user-2fcf,1 Jul 6 17:11:38 DEBUG[11842] channel.c: Done planning to masquerade channel SIP/4461-587e into the structure of Local/4461@user-2fcf,1 Jul 6 17:11:38 DEBUG[11838] channel.c: Actually Masquerading SIP/4461-587e(6) into the structure of Local/4461@user-2fcf,1(6) Jul 6 17:11:38 DEBUG[11842] chan_local.c: Not posting to queue since already masked on 'Local/4461@user-2fcf,2' Jul 6 17:11:38 DEBUG[11838] channel.c: Got clone lock for masquerade on 'SIP/4461-587e' at 0x81ca1d4 Jul 6 17:11:38 DEBUG[11838] channel.c: Set channel SIP/4461-587e to write format alaw Jul 6 17:11:38 DEBUG[11838] channel.c: Set channel SIP/4461-587e to read format alaw Jul 6 17:11:38 DEBUG[11838] channel.c: Putting channel SIP/4461-587e in 8/8 formats Jul 6 17:11:38 DEBUG[11838] channel.c: Released clone lock on 'Local/4461@user-2fcf,1' Jul 6 17:11:38 DEBUG[11838] channel.c: Done Masquerading SIP/4461-587e (6) Jul 6 17:11:38 DEBUG[11838] chan_agent.c: Bridge on 'SIP/4461-587e' being set to 'Agent/4461' (3) Jul 6 17:11:38 DEBUG[11842] channel.c: Didn't get a frame from channel: Local/4461@user-2fcf,2 Jul 6 17:11:38 DEBUG[11842] channel.c: Bridge stops bridging channels Local/4461@user-2fcf,2 and Local/4461@user-2fcf,1 Jul 6 17:11:38 DEBUG[11842] channel.c: Hanging up zombie 'Local/4461@user-2fcf,1' Jul 6 17:11:38 DEBUG[11842] app_dial.c: Exiting with DIALSTATUS=ANSWER. Jul 6 17:11:38 DEBUG[11842] pbx.c: Spawn extension (user,4461,1) exited non-zero on 'Local/4461@user-2fcf,2' Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4462@user-b43c,2' Jul 6 17:11:38 DEBUG[11759] chan_sip.c: Stopping retransmission on '6ca057163f0507f2780b53ae7d8d4875@192.168.0.200' of Request 102: Match Found Jul 6 17:11:38 DEBUG[11759] chan_sip.c: Stopping retransmission on '7530b2ae035dad71015f5cff041d8269@192.168.0.200' of Request 102: Match Found Jul 6 17:11:38 DEBUG[11759] chan_sip.c: Stopping retransmission on '7530b2ae035dad71015f5cff041d8269@192.168.0.200' of Request 102: Match Not Found Jul 6 17:11:38 DEBUG[11759] chan_sip.c: Updating call counter for outgoing call Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4462@user-b43c,2' Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4462@user-b43c,2' Jul 6 17:11:38 DEBUG[11759] chan_sip.c: Stopping retransmission on '6ca057163f0507f2780b53ae7d8d4875@192.168.0.200' of Request 102: Match Not Found Jul 6 17:11:38 DEBUG[11759] chan_sip.c: Updating call counter for outgoing call Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4462@user-b43c,2' Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4462@user-b43c,2' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is '"XXXX" ' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is 'anonymous' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is '4462' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is 'user' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is 'Local/4462@user-b43c,2' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is 'SIP/4462-72cf' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is 'Dial' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is 'SIP/4462|55|tTr' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is '2006-07-06 17:11:36' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is '(null)' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is '2006-07-06 17:11:38' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is '2' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is '0' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is 'NO ANSWER' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is 'DOCUMENTATION' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is '(null)' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is '1152198696.15' Jul 6 17:11:38 DEBUG[11841] pbx.c: Function result is '(null)' Jul 6 17:11:38 DEBUG[11841] channel.c: Hanging up channel 'Local/4462@user-b43c,2' Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Local/4462@user - state 0 (Unknown) Jul 6 17:11:38 DEBUG[11853] app_queue.c: Device 'Local/4462@user' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Agent/4462 - state 1 (Not in use) Jul 6 17:11:38 DEBUG[11854] app_queue.c: Device 'Agent/4462' changed to state '1' (Not in use) Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Agent/4462 - state 1 (Not in use) Jul 6 17:11:38 DEBUG[11855] app_queue.c: Device 'Agent/4462' changed to state '1' (Not in use) Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4460@user-e18d,2' Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4460@user-e18d,2' Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4460@user-e18d,2' Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4460@user-e18d,2' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is '"XXXX" ' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is 'anonymous' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is '4460' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is 'user' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is 'Local/4460@user-e18d,2' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is 'SIP/4460-8d74' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is 'Dial' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is 'SIP/4460|55|tTr' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is '2006-07-06 17:11:36' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is '(null)' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is '2006-07-06 17:11:38' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is '2' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is '0' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is 'NO ANSWER' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is 'DOCUMENTATION' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is '(null)' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is '1152198696.23' Jul 6 17:11:38 DEBUG[11843] pbx.c: Function result is '(null)' Jul 6 17:11:38 DEBUG[11843] channel.c: Hanging up channel 'Local/4460@user-e18d,2' Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Local/4460@user - state 0 (Unknown) Jul 6 17:11:38 DEBUG[11856] app_queue.c: Device 'Local/4460@user' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Agent/4460 - state 1 (Not in use) Jul 6 17:11:38 DEBUG[11857] app_queue.c: Device 'Agent/4460' changed to state '1' (Not in use) Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Agent/4460 - state 1 (Not in use) Jul 6 17:11:38 DEBUG[11858] app_queue.c: Device 'Agent/4460' changed to state '1' (Not in use) Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4461@user-2fcf,2' Jul 6 17:11:38 DEBUG[11748] channel.c: Avoiding initial deadlock for 'Local/4461@user-2fcf,2' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is '"XXXX" ' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is 'anonymous' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is '4461' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is 'user' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is 'Local/4461@user-2fcf,2' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is 'SIP/4461-587e' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is 'Dial' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is 'SIP/4461|55|tTr' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is '2006-07-06 17:11:36' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is '2006-07-06 17:11:38' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is '2006-07-06 17:11:38' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is '2' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is '0' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is 'ANSWERED' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is 'DOCUMENTATION' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is '(null)' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is '1152198696.19' Jul 6 17:11:38 DEBUG[11842] pbx.c: Function result is '(null)' Jul 6 17:11:38 DEBUG[11842] channel.c: Hanging up channel 'Local/4461@user-2fcf,2' Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Local/4461@user - state 0 (Unknown) Jul 6 17:11:38 DEBUG[11859] app_queue.c: Device 'Local/4461@user' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11748] chan_sip.c: Checking device state for peer 4462 Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for SIP/4462 - state 1 (Not in use) Jul 6 17:11:38 DEBUG[11860] app_queue.c: Device 'SIP/4462' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11748] chan_sip.c: Checking device state for peer 4460 Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for SIP/4460 - state 1 (Not in use) Jul 6 17:11:38 DEBUG[11861] app_queue.c: Device 'SIP/4460' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Local/4461@user - state 0 (Unknown) Jul 6 17:11:38 DEBUG[11862] app_queue.c: Device 'Local/4461@user' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Local/4462@user - state 0 (Unknown) Jul 6 17:11:38 DEBUG[11863] app_queue.c: Device 'Local/4462@user' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Local/4460@user - state 0 (Unknown) Jul 6 17:11:38 DEBUG[11864] app_queue.c: Device 'Local/4460@user' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11748] devicestate.c: Changing state for Local/4461@user - state 0 (Unknown) Jul 6 17:11:38 DEBUG[11865] app_queue.c: Device 'Local/4461@user' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Jul 6 17:11:38 DEBUG[11749] res_musiconhold.c: Only wrote -1 of 1600 bytes to pipe Jul 6 17:11:38 DEBUG[11749] res_musiconhold.c: Only wrote -1 of 1600 bytes to pipe Jul 6 17:11:38 DEBUG[11800] rtp.c: Difference is 2392, ms is 319 Jul 6 17:11:39 DEBUG[11800] rtp.c: Got RTCP report of 84 bytes Jul 6 17:11:41 DEBUG[11838] rtp.c: Got RTCP report of 112 bytes Jul 6 17:11:41 DEBUG[11838] channel.c: Set channel Agent/4461 to write format alaw Jul 6 17:11:41 DEBUG[11838] channel.c: Set channel SIP/06765765765-810e to write format alaw Jul 6 17:11:41 VERBOSE[11838] logger.c: -- Stopped music on hold on SIP/06765765765-810e Jul 6 17:11:41 DEBUG[11838] channel.c: Set channel SIP/06765765765-810e to read format alaw Jul 6 17:11:41 DEBUG[11838] channel.c: Set channel Agent/4461 to write format alaw Jul 6 17:11:41 DEBUG[11838] channel.c: Set channel Agent/4461 to read format alaw Jul 6 17:11:41 DEBUG[11838] channel.c: Set channel SIP/06765765765-810e to write format alaw Jul 6 17:11:43 DEBUG[11838] rtp.c: Got RTCP report of 112 bytes Jul 6 17:11:44 DEBUG[11759] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jul 6 17:11:44 DEBUG[11759] chan_agent.c: Asked for bridged channel on 'SIP/4461-587e'/'Agent/4461', returning 'SIP/06765765765-810e' Jul 6 17:11:44 DEBUG[11759] channel.c: Set channel SIP/06765765765-810e to write format slin Jul 6 17:11:44 VERBOSE[11759] logger.c: -- Started music on hold, class 'default', on channel 'SIP/06765765765-810e' Jul 6 17:11:44 DEBUG[11759] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jul 6 17:11:44 DEBUG[11759] chan_sip.c: Stopping retransmission on '1c94d0935d57790c7499f0df1d64f8bb@192.168.0.200' of Response 1: Match Found Jul 6 17:11:44 DEBUG[11838] rtp.c: Got RTCP report of 84 bytes Jul 6 17:11:48 DEBUG[11759] acl.c: ##### Testing 192.168.0.58 with 192.168.0.0 Jul 6 17:11:48 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for 197bb3a8-c0a80101-1-10@192.168.0.58 - INVITE (With RTP) Jul 6 17:11:48 DEBUG[11759] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jul 6 17:11:48 DEBUG[11759] chan_sip.c: * SIP extension value: 5 for call 197bb3a8-c0a80101-1-10@192.168.0.58 Jul 6 17:11:48 DEBUG[11759] chan_sip.c: Setting NAT on RTP to 0 Jul 6 17:11:48 DEBUG[11759] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jul 6 17:11:48 DEBUG[11759] chan_sip.c: Stopping retransmission on '197bb3a8-c0a80101-1-10@192.168.0.58' of Response 1: Match Found Jul 6 17:11:48 DEBUG[11759] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jul 6 17:11:48 DEBUG[11759] chan_sip.c: Setting NAT on RTP to 0 Jul 6 17:11:48 DEBUG[11759] chan_sip.c: Checking SIP call limits for device 4461 Jul 6 17:11:48 DEBUG[11759] chan_sip.c: Updating call counter for incoming call Jul 6 17:11:48 DEBUG[11759] chan_sip.c: build_route: Contact hop: Jul 6 17:11:48 DEBUG[11866] pbx.c: Launching 'Dial' Jul 6 17:11:48 VERBOSE[11866] logger.c: -- Executing Dial("SIP/4461-e64b", "SIP/4460|55|tTr") in new stack Jul 6 17:11:48 DEBUG[11866] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jul 6 17:11:48 DEBUG[11866] chan_sip.c: Setting NAT on RTP to 0 Jul 6 17:11:48 DEBUG[11866] acl.c: ##### Testing 192.168.0.60 with 192.168.0.0 Jul 6 17:11:48 DEBUG[11866] channel.c: Not copying variable STACK-user-4460-1. Jul 6 17:11:48 DEBUG[11866] channel.c: Not copying variable SIPCALLID. Jul 6 17:11:48 DEBUG[11866] channel.c: Not copying variable SIPUSERAGENT. Jul 6 17:11:48 DEBUG[11866] channel.c: Not copying variable SIPDOMAIN. Jul 6 17:11:48 DEBUG[11866] channel.c: Not copying variable SIPURI. Jul 6 17:11:48 DEBUG[11866] chan_sip.c: Outgoing Call for 4460 Jul 6 17:11:48 DEBUG[11866] chan_sip.c: Updating call counter for outgoing call Jul 6 17:11:48 VERBOSE[11866] logger.c: -- Called 4460 Jul 6 17:11:48 DEBUG[11748] chan_sip.c: Checking device state for peer 4461 Jul 6 17:11:48 DEBUG[11748] devicestate.c: Changing state for SIP/4461 - state 2 (In use) Jul 6 17:11:48 DEBUG[11867] app_queue.c: Device 'SIP/4461' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 6 17:11:48 DEBUG[11759] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1d4afe777f40479c3e62a4da35843437@192.168.0.200' Request 102: Found Jul 6 17:11:48 DEBUG[11759] chan_sip.c: SIP response 100 to standard invite Jul 6 17:11:48 DEBUG[11759] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1d4afe777f40479c3e62a4da35843437@192.168.0.200' Request 102: Found Jul 6 17:11:48 DEBUG[11759] chan_sip.c: SIP response 180 to standard invite Jul 6 17:11:48 VERBOSE[11866] logger.c: -- SIP/4460-1ee1 is ringing Jul 6 17:11:48 DEBUG[11748] chan_sip.c: Checking device state for peer 4460 Jul 6 17:11:48 DEBUG[11748] devicestate.c: Changing state for SIP/4460 - state 6 (Ringing) Jul 6 17:11:48 DEBUG[11868] app_queue.c: Device 'SIP/4460' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Jul 6 17:11:49 DEBUG[11838] rtp.c: Got RTCP report of 84 bytes Jul 6 17:11:54 DEBUG[11838] rtp.c: Got RTCP report of 84 bytes Jul 6 17:11:54 DEBUG[11759] chan_sip.c: Acked pending invite 102 Jul 6 17:11:54 DEBUG[11759] chan_sip.c: Stopping retransmission on '1d4afe777f40479c3e62a4da35843437@192.168.0.200' of Request 102: Match Found Jul 6 17:11:54 DEBUG[11759] chan_sip.c: SIP response 200 to standard invite Jul 6 17:11:54 DEBUG[11759] chan_sip.c: build_route: Contact hop: Jul 6 17:11:54 VERBOSE[11866] logger.c: -- SIP/4460-1ee1 answered SIP/4461-e64b Jul 6 17:11:54 DEBUG[11866] channel.c: Set channel SIP/4461-e64b to read format alaw Jul 6 17:11:54 DEBUG[11866] channel.c: Set channel SIP/4460-1ee1 to write format alaw Jul 6 17:11:54 DEBUG[11866] channel.c: Set channel SIP/4460-1ee1 to read format alaw Jul 6 17:11:54 DEBUG[11866] channel.c: Set channel SIP/4461-e64b to write format alaw Jul 6 17:11:54 DEBUG[11866] chan_sip.c: sip_answer(SIP/4461-e64b) Jul 6 17:11:54 VERBOSE[11866] logger.c: -- Attempting native bridge of SIP/4461-e64b and SIP/4460-1ee1 Jul 6 17:11:54 DEBUG[11748] chan_sip.c: Checking device state for peer 4460 Jul 6 17:11:54 DEBUG[11748] devicestate.c: Changing state for SIP/4460 - state 2 (In use) Jul 6 17:11:54 DEBUG[11869] app_queue.c: Device 'SIP/4460' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 6 17:11:54 DEBUG[11748] chan_sip.c: Checking device state for peer 4461 Jul 6 17:11:54 DEBUG[11748] devicestate.c: Changing state for SIP/4461 - state 2 (In use) Jul 6 17:11:54 DEBUG[11870] app_queue.c: Device 'SIP/4461' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 6 17:11:54 DEBUG[11759] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jul 6 17:11:54 DEBUG[11759] chan_sip.c: Stopping retransmission on '197bb3a8-c0a80101-1-10@192.168.0.58' of Response 2: Match Found Jul 6 17:11:54 DEBUG[11866] rtp.c: Ooh, format changed from unknown to alaw Jul 6 17:11:54 DEBUG[11866] rtp.c: Ooh, format changed from unknown to alaw Jul 6 17:11:57 DEBUG[11866] rtp.c: Got RTCP report of 112 bytes Jul 6 17:11:57 DEBUG[11866] rtp.c: Got RTCP report of 112 bytes Jul 6 17:11:59 DEBUG[11838] rtp.c: Got RTCP report of 84 bytes Jul 6 17:11:59 DEBUG[11866] rtp.c: Got RTCP report of 112 bytes Jul 6 17:11:59 DEBUG[11866] rtp.c: Got RTCP report of 112 bytes Jul 6 17:12:02 DEBUG[11759] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jul 6 17:12:02 DEBUG[11759] channel.c: Set channel SIP/4460-1ee1 to write format slin Jul 6 17:12:02 VERBOSE[11759] logger.c: -- Started music on hold, class 'default', on channel 'SIP/4460-1ee1' Jul 6 17:12:02 DEBUG[11759] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jul 6 17:12:02 DEBUG[11759] chan_sip.c: Stopping retransmission on '197bb3a8-c0a80101-1-10@192.168.0.58' of Response 3: Match Found Jul 6 17:12:02 DEBUG[11866] rtp.c: Got RTCP report of 112 bytes Jul 6 17:12:03 DEBUG[11759] chan_sip.c: **** Received REFER (9) - Command in SIP REFER Jul 6 17:12:03 DEBUG[11759] chan_sip.c: SIP call transfer received for call 1c94d0935d57790c7499f0df1d64f8bb@192.168.0.200 (REFER)! Jul 6 17:12:03 DEBUG[11759] chan_sip.c: Assigning Replace-Call-ID Info 197bb3a8-c0a80101-1-10@192.168.0.58 to REPLACE_CALL_ID Jul 6 17:12:03 DEBUG[11759] chan_sip.c: 202 Accepted (supervised) Jul 6 17:12:03 DEBUG[11759] chan_agent.c: Asked for bridged channel on 'SIP/4461-587e'/'Agent/4461', returning 'SIP/06765765765-810e' Jul 6 17:12:03 DEBUG[11759] channel.c: Set channel SIP/06765765765-810e to write format alaw Jul 6 17:12:03 VERBOSE[11759] logger.c: -- Stopped music on hold on SIP/06765765765-810e Jul 6 17:12:03 DEBUG[11759] channel.c: Set channel SIP/4460-1ee1 to write format alaw Jul 6 17:12:03 VERBOSE[11759] logger.c: -- Stopped music on hold on SIP/4460-1ee1 Jul 6 17:12:03 DEBUG[11759] chan_agent.c: Asked for bridged channel on 'SIP/06765765765-810e'/'Agent/4461', returning 'SIP/4461-587e' Jul 6 17:12:03 DEBUG[11759] channel.c: Planning to masquerade channel Agent/4461 into the structure of SIP/4461-e64b Jul 6 17:12:03 DEBUG[11838] channel.c: Nobody there, continuing... Jul 6 17:12:03 DEBUG[11759] channel.c: Done planning to masquerade channel Agent/4461 into the structure of SIP/4461-e64b Jul 6 17:12:03 DEBUG[11866] channel.c: Actually Masquerading Agent/4461(6) into the structure of SIP/4461-e64b(6) Jul 6 17:12:03 DEBUG[11866] channel.c: Got clone lock for masquerade on 'Agent/4461' at 0x818f294 Jul 6 17:12:03 DEBUG[11866] chan_sip.c: Hangup call Agent/4461, SIP callid 197bb3a8-c0a80101-1-10@192.168.0.58) Jul 6 17:12:03 DEBUG[11866] chan_sip.c: update_call_counter(4461) - decrement call limit counter Jul 6 17:12:03 DEBUG[11866] chan_sip.c: Updating call counter for incoming call Jul 6 17:12:03 DEBUG[11866] channel.c: Set channel Agent/4461 to write format alaw Jul 6 17:12:03 DEBUG[11866] channel.c: Set channel Agent/4461 to read format alaw Jul 6 17:12:03 DEBUG[11866] channel.c: Putting channel Agent/4461 in 8/8 formats Jul 6 17:12:03 DEBUG[11866] channel.c: Released clone lock on 'SIP/4461-e64b' Jul 6 17:12:03 DEBUG[11866] channel.c: Done Masquerading Agent/4461 (6) Jul 6 17:12:03 DEBUG[11759] chan_sip.c: Stopping retransmission on '197bb3a8-c0a80101-1-10@192.168.0.58' of Request 102: Match Found Jul 6 17:12:03 DEBUG[11838] channel.c: Bridge stops because we're zombie or need a soft hangup: c0=SIP/06765765765-810e, c1=SIP/4461-e64b, flags: No,No,Yes,Yes Jul 6 17:12:03 DEBUG[11838] channel.c: Bridge stops bridging channels SIP/06765765765-810e and SIP/4461-e64b Jul 6 17:12:03 DEBUG[11838] channel.c: Hanging up zombie 'SIP/4461-e64b' Jul 6 17:12:03 DEBUG[11838] pbx.c: Spawn extension (qscin,06765765765,11) exited non-zero on 'SIP/06765765765-810e' Jul 6 17:12:03 DEBUG[11838] channel.c: Hanging up channel 'SIP/06765765765-810e' Jul 6 17:12:03 DEBUG[11838] chan_sip.c: Hangup call SIP/06765765765-810e, SIP callid d860151fcaf0814bb12c591e31561eca@sx3000) Jul 6 17:12:03 DEBUG[11838] chan_sip.c: update_call_counter(06765765765) - decrement call limit counter Jul 6 17:12:03 DEBUG[11838] chan_sip.c: Updating call counter for incoming call Jul 6 17:12:03 DEBUG[11748] chan_sip.c: Checking device state for peer 4461 Jul 6 17:12:03 DEBUG[11748] devicestate.c: Changing state for SIP/4461 - state 2 (In use) Jul 6 17:12:03 DEBUG[11871] app_queue.c: Device 'SIP/4461' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 6 17:12:03 DEBUG[11748] chan_sip.c: Checking device state for peer 06765765765 Jul 6 17:12:03 DEBUG[11748] devicestate.c: Changing state for SIP/06765765765 - state 1 (Not in use) Jul 6 17:12:03 DEBUG[11872] app_queue.c: Device 'SIP/06765765765' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jul 6 17:12:03 DEBUG[11759] chan_sip.c: Stopping retransmission on '1c94d0935d57790c7499f0df1d64f8bb@192.168.0.200' of Request 103: Match Found Jul 6 17:12:03 DEBUG[11759] chan_sip.c: **** Received BYE (8) - Command in SIP BYE Jul 6 17:12:03 DEBUG[11866] channel.c: Didn't get a frame from channel: Agent/4461 Jul 6 17:12:03 DEBUG[11866] channel.c: Bridge stops bridging channels Agent/4461 and SIP/4460-1ee1 Jul 6 17:12:03 DEBUG[11866] channel.c: Hanging up channel 'SIP/4460-1ee1' Jul 6 17:12:03 DEBUG[11866] chan_sip.c: Hangup call SIP/4460-1ee1, SIP callid 1d4afe777f40479c3e62a4da35843437@192.168.0.200) Jul 6 17:12:03 DEBUG[11866] chan_sip.c: update_call_counter(4460) - decrement call limit counter Jul 6 17:12:03 DEBUG[11866] chan_sip.c: Updating call counter for outgoing call Jul 6 17:12:03 DEBUG[11866] app_dial.c: Exiting with DIALSTATUS=ANSWER. Jul 6 17:12:03 DEBUG[11866] pbx.c: Spawn extension (user,4460,1) exited non-zero on 'Agent/4461' Jul 6 17:12:03 DEBUG[11759] chan_sip.c: Stopping retransmission on '1c94d0935d57790c7499f0df1d64f8bb@192.168.0.200' of Request 104: Match Found Jul 6 17:12:03 DEBUG[11748] chan_sip.c: Checking device state for peer 4460 Jul 6 17:12:03 DEBUG[11748] devicestate.c: Changing state for SIP/4460 - state 1 (Not in use) Jul 6 17:12:03 DEBUG[11873] app_queue.c: Device 'SIP/4460' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jul 6 17:12:03 DEBUG[11759] chan_sip.c: Stopping retransmission on '1d4afe777f40479c3e62a4da35843437@192.168.0.200' of Request 103: Match Found Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '"XXXX" ' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'anonymous' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '4460' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'user' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'SIP/4461-e64b' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'SIP/4460-1ee1' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'Dial' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'SIP/4460|55|tTr' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '2006-07-06 17:11:48' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '2006-07-06 17:11:54' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '2006-07-06 17:12:03' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '15' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '9' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'ANSWERED' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'DOCUMENTATION' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '(null)' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '1152198708.26' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '(null)' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '"XXXX" ' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'anonymous' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '4460' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'user' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'SIP/06765765765-810e' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'Agent/4461' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'Queue' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'qrb24|Tt' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '2006-07-06 17:11:20' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '2006-07-06 17:11:24' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '2006-07-06 17:12:03' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '43' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '39' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'ANSWERED' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is 'DOCUMENTATION' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '(null)' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '1152198680.13' Jul 6 17:12:03 DEBUG[11866] pbx.c: Function result is '(null)' Jul 6 17:12:03 DEBUG[11866] channel.c: Hanging up channel 'Agent/4461' Jul 6 17:12:03 DEBUG[11866] chan_agent.c: Hangup called for state Up Jul 6 17:12:03 DEBUG[11866] channel.c: Hanging up channel 'SIP/4461-587e' Jul 6 17:12:03 DEBUG[11866] chan_sip.c: Hangup call SIP/4461-587e, SIP callid 1c94d0935d57790c7499f0df1d64f8bb@192.168.0.200) Jul 6 17:12:03 DEBUG[11866] chan_sip.c: update_call_counter(4461) - decrement call limit counter Jul 6 17:12:03 DEBUG[11866] chan_sip.c: Updating call counter for incoming call Jul 6 17:12:03 DEBUG[11866] chan_agent.c: Hungup, howlong is 0, autologoff is 0 Jul 6 17:12:03 DEBUG[11759] chan_sip.c: Stopping retransmission on 'd860151fcaf0814bb12c591e31561eca@sx3000' of Request 102: Match Found Jul 6 17:12:03 DEBUG[11748] chan_sip.c: Checking device state for peer 4461 Jul 6 17:12:03 DEBUG[11748] devicestate.c: Changing state for SIP/4461 - state 1 (Not in use) Jul 6 17:12:03 DEBUG[11874] app_queue.c: Device 'SIP/4461' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jul 6 17:12:03 DEBUG[11748] devicestate.c: Changing state for Agent/4461 - state 1 (Not in use) Jul 6 17:12:03 DEBUG[11875] app_queue.c: Device 'Agent/4461' changed to state '1' (Not in use) Jul 6 17:12:03 DEBUG[11748] devicestate.c: Changing state for Agent/4461 - state 1 (Not in use) Jul 6 17:12:03 DEBUG[11876] app_queue.c: Device 'Agent/4461' changed to state '1' (Not in use) Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for 37ee1c3e6523a73c2086216548557427@192.168.0.200 - REGISTER (No RTP) Jul 6 17:12:08 DEBUG[11759] acl.c: ##### Testing 213.148.136.2 with 192.168.0.0 Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Target address 213.148.136.2 is not local, substituting externip Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Scheduled a registration timeout for provider id #145 Jul 6 17:12:08 VERBOSE[11759] logger.c: REGISTER attempt 1 to 03075659443@provider Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Stopping retransmission on '37ee1c3e6523a73c2086216548557427@192.168.0.200' of Request 105: Match Found Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Registration successful Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Cancelling timeout 145 Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for 229258942152e1fc5c338eb0125643d3@192.168.0.200 - REGISTER (No RTP) Jul 6 17:12:08 DEBUG[11759] acl.c: ##### Testing 213.148.136.2 with 192.168.0.0 Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Target address 213.148.136.2 is not local, substituting externip Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Scheduled a registration timeout for provider id #149 Jul 6 17:12:08 VERBOSE[11759] logger.c: REGISTER attempt 1 to 03075765941@provider Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Stopping retransmission on '229258942152e1fc5c338eb0125643d3@192.168.0.200' of Request 105: Match Found Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Registration successful Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Cancelling timeout 149 Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for 717c5ea5339082ea1be3994011b7a729@192.168.0.200 - REGISTER (No RTP) Jul 6 17:12:08 DEBUG[11759] acl.c: ##### Testing 213.148.136.2 with 192.168.0.0 Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Target address 213.148.136.2 is not local, substituting externip Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Scheduled a registration timeout for provider id #153 Jul 6 17:12:08 VERBOSE[11759] logger.c: REGISTER attempt 1 to 03075765942@provider Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Stopping retransmission on '717c5ea5339082ea1be3994011b7a729@192.168.0.200' of Request 105: Match Found Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Registration successful Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Cancelling timeout 153 Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for 5083d58367b998ff39a944342f5a52fe@192.168.0.200 - REGISTER (No RTP) Jul 6 17:12:08 DEBUG[11759] acl.c: ##### Testing 213.148.136.2 with 192.168.0.0 Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Target address 213.148.136.2 is not local, substituting externip Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Scheduled a registration timeout for provider id #157 Jul 6 17:12:08 VERBOSE[11759] logger.c: REGISTER attempt 1 to 03075765941@provider Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Stopping retransmission on '5083d58367b998ff39a944342f5a52fe@192.168.0.200' of Request 105: Match Found Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Registration successful Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Cancelling timeout 157 Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for 4721c3603708c7666f453f9457cb823a@192.168.0.200 - REGISTER (No RTP) Jul 6 17:12:08 DEBUG[11759] acl.c: ##### Testing 213.148.136.2 with 192.168.0.0 Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Target address 213.148.136.2 is not local, substituting externip Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Scheduled a registration timeout for provider id #161 Jul 6 17:12:08 VERBOSE[11759] logger.c: REGISTER attempt 1 to 03075765191@provider Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Stopping retransmission on '4721c3603708c7666f453f9457cb823a@192.168.0.200' of Request 105: Match Found Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Registration successful Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Cancelling timeout 161 Jul 6 17:12:08 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for 49bcb1a937196d5e2d9142a035890ffa@192.168.0.200 - REGISTER (No RTP) Jul 6 17:12:09 DEBUG[11759] acl.c: ##### Testing 213.148.136.2 with 192.168.0.0 Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Target address 213.148.136.2 is not local, substituting externip Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Scheduled a registration timeout for provider id #165 Jul 6 17:12:09 VERBOSE[11759] logger.c: REGISTER attempt 1 to 03020007793@provider Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Stopping retransmission on '49bcb1a937196d5e2d9142a035890ffa@192.168.0.200' of Request 105: Match Found Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Registration successful Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Cancelling timeout 165 Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for 65da0e2c4d93a72b073ceb5f36973e5e@192.168.0.200 - REGISTER (No RTP) Jul 6 17:12:09 DEBUG[11759] acl.c: ##### Testing 213.148.136.2 with 192.168.0.0 Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Target address 213.148.136.2 is not local, substituting externip Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Scheduled a registration timeout for provider id #169 Jul 6 17:12:09 VERBOSE[11759] logger.c: REGISTER attempt 1 to 03020007748@provider Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Stopping retransmission on '65da0e2c4d93a72b073ceb5f36973e5e@192.168.0.200' of Request 105: Match Found Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Registration successful Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Cancelling timeout 169 Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for 0f097f64461246cb3557865f0d230899@192.168.0.200 - REGISTER (No RTP) Jul 6 17:12:09 DEBUG[11759] acl.c: ##### Testing 213.148.136.2 with 192.168.0.0 Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Target address 213.148.136.2 is not local, substituting externip Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Scheduled a registration timeout for provider id #173 Jul 6 17:12:09 VERBOSE[11759] logger.c: REGISTER attempt 1 to 06765765765@provider Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Stopping retransmission on '0f097f64461246cb3557865f0d230899@192.168.0.200' of Request 105: Match Found Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Registration successful Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Cancelling timeout 173 Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for 3cd61c90050afda600c329e244bf897e@192.168.0.200 - REGISTER (No RTP) Jul 6 17:12:09 DEBUG[11759] acl.c: ##### Testing 213.148.136.2 with 192.168.0.0 Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Target address 213.148.136.2 is not local, substituting externip Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Scheduled a registration timeout for provider id #177 Jul 6 17:12:09 VERBOSE[11759] logger.c: REGISTER attempt 1 to 06765765765@provider Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Allocating new SIP dialog for 6fd4b4cb04bc75db4a42cafc2113f900@192.168.0.200 - REGISTER (No RTP) Jul 6 17:12:09 DEBUG[11759] acl.c: ##### Testing 213.148.136.2 with 192.168.0.0 Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Target address 213.148.136.2 is not local, substituting externip Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Scheduled a registration timeout for provider id #179 Jul 6 17:12:09 VERBOSE[11759] logger.c: REGISTER attempt 1 to 06222948402@provider Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Stopping retransmission on '3cd61c90050afda600c329e244bf897e@192.168.0.200' of Request 105: Match Found Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Registration successful Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Cancelling timeout 177 Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Stopping retransmission on '6fd4b4cb04bc75db4a42cafc2113f900@192.168.0.200' of Request 105: Match Found Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Registration successful Jul 6 17:12:09 DEBUG[11759] chan_sip.c: Cancelling timeout 179