Dec 20 14:14:45 DEBUG[2496]: ##### Testing 192.168.0.102 with 192.168.0.0 Dec 20 14:14:45 DEBUG[2496]: ##### Testing 192.168.0.102 with 0.0.0.0 Dec 20 14:14:45 DEBUG[2496]: ##### Testing 192.168.0.102 with 192.168.0.0 Dec 20 14:14:45 DEBUG[2496]: Setting NAT on RTP to 0 Dec 20 14:14:45 DEBUG[2496]: Stopping retransmission on '001192d9-88250005-48699ec0-0cf291e3@192.168 .0.102' of Response 101: Found Dec 20 14:14:45 DEBUG[2496]: ##### Testing 192.168.0.102 with 0.0.0.0 Dec 20 14:14:45 DEBUG[2496]: ##### Testing 192.168.0.102 with 192.168.0.0 Dec 20 14:14:45 DEBUG[2496]: Setting NAT on RTP to 0 Dec 20 14:14:45 DEBUG[2496]: Check for res for 2 Dec 20 14:14:45 DEBUG[2496]: Call from user '2' is 1 out of 0 Dec 20 14:14:45 DEBUG[2496]: build_route: Contact hop: Dec 20 14:14:45 DEBUG[2684]: Device 'SIP/2' changed to state '2' Dec 20 14:14:45 VERBOSE[2685]: -- Executing NoOp("SIP/2-936f ", "Chiamata a interni SIP") in new stack Dec 20 14:14:45 VERBOSE[2685]: -- Executing Macro("SIP/2-936f ", "interni|SIP|1|90") in new stack Dec 20 14:14:45 VERBOSE[2685]: -- Executing NoCDR("SIP/2-936f ", "") in new stack Dec 20 14:14:45 WARNING[2685]: CDR on channel 'SIP/2-936f' not posted Dec 20 14:14:45 WARNING[2685]: CDR on channel 'SIP/2-936f' lacks end Dec 20 14:14:45 VERBOSE[2685]: -- Executing SetVar("SIP/2-936f ", "_ALERT_INFO=") in new stack Dec 20 14:14:45 VERBOSE[2685]: -- Executing Answer("SIP/2-936f ", "") in new stack Dec 20 14:14:45 VERBOSE[2685]: -- Executing Dial("SIP/2-936f ", "SIP/1|90|tT") in new stack Dec 20 14:14:45 DEBUG[2685]: Setting NAT on RTP to 0 Dec 20 14:14:45 DEBUG[2685]: ##### Testing 192.168.0.101 with 192.168.0.0 Dec 20 14:14:45 DEBUG[2685]: Outgoing Call for 1 Dec 20 14:14:45 DEBUG[2685]: Call from user '1' is 1 out of 0 Dec 20 14:14:45 VERBOSE[2685]: -- Called 1 Dec 20 14:14:46 DEBUG[2496]: Stopping retransmission on '001192d9-88250005-48699ec0-0cf291e3@192.168 .0.102' of Response 102: Found Dec 20 14:14:46 DEBUG[2496]: (Provisional) Stopping retransmission (but retaining packet) on '2d583a e404b5d4c351b5e354054843d0@192.168.0.100' Request 102: Found Dec 20 14:14:46 DEBUG[2496]: (Provisional) Stopping retransmission (but retaining packet) on '2d583a e404b5d4c351b5e354054843d0@192.168.0.100' Request 102: Found Dec 20 14:14:46 VERBOSE[2685]: -- SIP/1-ae8c is ringing Dec 20 14:14:46 DEBUG[2685]: Driver for channel 'SIP/2-936f' does not support indication 3, emulatin g it Dec 20 14:14:46 DEBUG[2685]: Scheduling timer at 160 sample intervals Dec 20 14:14:46 DEBUG[2686]: Device 'SIP/1' changed to state '2' Dec 20 14:14:46 DEBUG[2685]: Generator got voice, switching to phase locked mode Dec 20 14:14:46 DEBUG[2685]: Scheduling timer at 0 sample intervals Dec 20 14:14:46 DEBUG[2685]: Ooh, format changed from unknown to alaw Dec 20 14:14:50 DEBUG[2496]: Acked pending invite 102 Dec 20 14:14:50 DEBUG[2496]: Stopping retransmission on '2d583ae404b5d4c351b5e354054843d0@192.168.0. 100' of Request 102: Found Dec 20 14:14:50 DEBUG[2496]: build_route: Contact hop: Dec 20 14:14:50 VERBOSE[2685]: -- SIP/1-ae8c answered SIP/2-936f Dec 20 14:14:50 DEBUG[2685]: Scheduling timer at 0 sample intervals Dec 20 14:14:50 VERBOSE[2685]: -- Attempting native bridge of SIP/2-936f and SIP/1-ae8c Dec 20 14:14:50 DEBUG[2685]: Ooh, format changed from unknown to alaw Dec 20 14:14:55 VERBOSE[2496]: -- Started music on hold, class 'default', on SIP/2-936f Dec 20 14:14:55 DEBUG[2496]: Scheduling timer at 160 sample intervals Dec 20 14:14:55 DEBUG[2685]: Generator got voice, switching to phase locked mode Dec 20 14:14:55 DEBUG[2685]: Scheduling timer at 0 sample intervals Dec 20 14:15:01 WARNING[2496]: Maximum retries exceeded on call 2d583ae404b5d4c351b5e354054843d0@192 .168.0.100 for seqno 101 (Non-critical Response) Dec 20 14:15:16 VERBOSE[2685]: -- Stopped music on hold on SIP/2-936f Dec 20 14:15:16 DEBUG[2685]: Scheduling timer at 0 sample intervals Dec 20 14:15:16 DEBUG[2685]: Didn't get a frame from channel: SIP/2-936f Dec 20 14:15:16 DEBUG[2685]: Bridge stops bridging channels SIP/2-936f and SIP/1-ae8c Dec 20 14:15:16 DEBUG[2685]: update_user_counter(1) - decrement inUse counter Dec 20 14:15:16 DEBUG[2685]: Exiting with DIALSTATUS=ANSWER. Dec 20 14:15:16 VERBOSE[2685]: == Spawn extension (macro-interni, s, 4) exited non-zero on 'SIP/2- 936f' in macro 'interni' Dec 20 14:15:16 VERBOSE[2685]: == Spawn extension (sip, 1, 2) exited non-zero on 'SIP/2-936f' Dec 20 14:15:16 DEBUG[2685]: update_user_counter(2) - decrement inUse counter Dec 20 14:15:16 DEBUG[2687]: Device 'SIP/1' changed to state '0' Dec 20 14:15:16 DEBUG[2688]: Device 'SIP/2' changed to state '0'