Feb 3 14:37:18 NOTICE[29379]: cdr_odbc: Logging uniqueid Feb 3 14:37:18 WARNING[29379]: Cannot open '/var/tmp/iaxy.bin-44059838' for writing: Permission denied Feb 3 14:37:23 VERBOSE[29379]: [skipping pbx_spool.so] Feb 3 14:37:23 VERBOSE[29379]: [skipping pbx_wilcalu.so] Feb 3 14:37:23 VERBOSE[29379]: [skipping res_config_odbc.so] Feb 3 14:37:23 VERBOSE[29379]: [skipping res_odbc.so] Feb 3 14:37:23 VERBOSE[29379]: [skipping chan_vpb.so] Feb 3 14:37:23 VERBOSE[29379]: [skipping pbx_gtkconsole.so] Feb 3 14:37:23 VERBOSE[29379]: == Parsing '/etc/asterisk/enum.conf': Feb 3 14:37:23 VERBOSE[29379]: == Parsing '/etc/asterisk/enum.conf': Found Feb 3 14:37:23 VERBOSE[29379]: == Parsing '/etc/asterisk/extconfig.conf': Feb 3 14:37:23 VERBOSE[29379]: == Parsing '/etc/asterisk/extconfig.conf': Found Feb 3 14:37:23 VERBOSE[29379]: Asterisk Event Logger restarted Feb 3 14:37:23 VERBOSE[29379]: == Parsing '/etc/asterisk/manager.conf': Feb 3 14:37:23 VERBOSE[29379]: == Parsing '/etc/asterisk/manager.conf': Found Feb 3 14:37:23 VERBOSE[29379]: == Parsing '/etc/asterisk/enum.conf': Feb 3 14:37:23 VERBOSE[29379]: == Parsing '/etc/asterisk/enum.conf': Found Feb 3 14:37:23 VERBOSE[29379]: == Parsing '/etc/asterisk/rtp.conf': Feb 3 14:37:23 VERBOSE[29379]: == Parsing '/etc/asterisk/rtp.conf': Found Feb 3 14:37:23 VERBOSE[29379]: == RTP Allocating from port range 10000 -> 20000 Feb 3 14:37:23 VERBOSE[29379]: Asterisk Ready. Feb 3 14:37:24 WARNING[29417]: Maximum retries exceeded on call 2114b6b93ebd9d8b7f3b644648b7dd8c@200.196.44.5 for seqno 102 (Non-critical Request) Feb 3 14:37:24 WARNING[29417]: Maximum retries exceeded on call 0430a5675197c1780a4a01ef485e000b@200.196.44.5 for seqno 102 (Non-critical Request) Feb 3 14:37:33 DEBUG[29417]: Auto destroying call '2114b6b93ebd9d8b7f3b644648b7dd8c@200.196.44.5' Feb 3 14:37:33 DEBUG[29417]: Auto destroying call '0430a5675197c1780a4a01ef485e000b@200.196.44.5' Feb 3 14:37:45 DEBUG[29422]: Manager received command 'login' Feb 3 14:37:45 VERBOSE[29422]: == Parsing '/etc/asterisk/manager.conf': Feb 3 14:37:45 VERBOSE[29422]: == Parsing '/etc/asterisk/manager.conf': Found Feb 3 14:37:45 DEBUG[29422]: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer Feb 3 14:37:45 DEBUG[29422]: ##### Testing 200.196.42.227 with 0.0.0.0 Feb 3 14:37:45 VERBOSE[29422]: == Manager 'bhsoft' logged on from 200.196.42.227 Feb 3 14:37:52 DEBUG[29416]: Unable to find key 'si-000fd3000a41' in family 'iax/provisioning/cache' Feb 3 14:37:52 DEBUG[29416]: Unable to create provisioning packet for 'si-000fd3000a41' Feb 3 14:37:52 DEBUG[29417]: Auto destroying call 'DE7CF6354CF1494F9E6C07F5D610EDF2@gateway.planetarium.com.br' Feb 3 14:38:07 DEBUG[29432]: Manager received command 'login' Feb 3 14:38:07 VERBOSE[29432]: == Parsing '/etc/asterisk/manager.conf': Feb 3 14:38:07 VERBOSE[29432]: == Parsing '/etc/asterisk/manager.conf': Found Feb 3 14:38:07 DEBUG[29432]: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer Feb 3 14:38:07 DEBUG[29432]: ##### Testing 200.196.42.227 with 0.0.0.0 Feb 3 14:38:07 VERBOSE[29432]: == Manager 'bhsoft' logged on from 200.196.42.227 Feb 3 14:38:07 DEBUG[29432]: Manager received command 'queueadd' Feb 3 14:38:07 DEBUG[29432]: Manager received command 'queueadd' Feb 3 14:38:07 DEBUG[29432]: Manager received command 'originate' Feb 3 14:38:07 DEBUG[29432]: Setting NAT on RTP to 0 Feb 3 14:38:07 DEBUG[29432]: Outgoing Call for 3052 Feb 3 14:38:07 DEBUG[29432]: Call from user '3052' is 1 out of 0 Feb 3 14:38:07 DEBUG[29417]: (Provisional) Stopping retransmission (but retaining packet) on '43fd588943dd0a2e01b288567b6f3b78@200.196.44.5' Request 102: Found Feb 3 14:38:07 DEBUG[29417]: (Provisional) Stopping retransmission (but retaining packet) on '43fd588943dd0a2e01b288567b6f3b78@200.196.44.5' Request 102: Found Feb 3 14:38:09 DEBUG[29417]: Acked pending invite 102 Feb 3 14:38:09 DEBUG[29417]: Stopping retransmission on '43fd588943dd0a2e01b288567b6f3b78@200.196.44.5' of Request 102: Found Feb 3 14:38:09 DEBUG[29417]: build_route: Contact hop: Feb 3 14:38:09 VERBOSE[29432]: > Channel SIP/3052-2db0 was answered. Feb 3 14:38:09 DEBUG[29432]: Manager received command 'queuestatus' Feb 3 14:38:09 DEBUG[29432]: Manager received command 'queuestatus' Feb 3 14:38:09 VERBOSE[29433]: -- Executing Answer("SIP/3052-2db0", "") in new stack Feb 3 14:38:09 VERBOSE[29433]: -- Executing Wait("SIP/3052-2db0", "1") in new stack Feb 3 14:38:09 DEBUG[29432]: Manager received command 'Status' Feb 3 14:38:10 VERBOSE[29433]: -- Executing SetAMAFlags("SIP/3052-2db0", "documentation") in new stack Feb 3 14:38:10 VERBOSE[29433]: -- Executing Goto("SIP/3052-2db0", "100") in new stack Feb 3 14:38:10 VERBOSE[29433]: -- Goto (agente_out,*53,100) Feb 3 14:38:10 VERBOSE[29433]: -- Executing AgentLogin("SIP/3052-2db0", "8031") in new stack Feb 3 14:38:10 DEBUG[29433]: Ooh, format changed from unknown to alaw Feb 3 14:38:10 DEBUG[29433]: Scheduling timer at 160 sample intervals Feb 3 14:38:10 VERBOSE[29433]: -- Playing 'agent-loginok' (language 'en') Feb 3 14:38:12 DEBUG[29433]: Scheduling timer at 0 sample intervals Feb 3 14:38:12 DEBUG[29433]: Scheduling timer at 0 sample intervals Feb 3 14:38:12 VERBOSE[29433]: -- Started music on hold, class 'silencio', on SIP/3052-2db0 Feb 3 14:38:12 DEBUG[29433]: Scheduling timer at 160 sample intervals Feb 3 14:38:12 VERBOSE[29433]: -- Agent '8031' logged in (format alaw/slin) Feb 3 14:38:12 DEBUG[29433]: Checking availability of '8031' Feb 3 14:38:12 DEBUG[29433]: Generator got voice, switching to phase locked mode Feb 3 14:38:12 DEBUG[29433]: Scheduling timer at 0 sample intervals Feb 3 14:38:18 DEBUG[29417]: Stopping retransmission on '481d59da79e72fab47682b9b37772851@200.196.44.5' of Request 102: Found Feb 3 14:38:24 DEBUG[29434]: Manager received command 'login' Feb 3 14:38:24 VERBOSE[29434]: == Parsing '/etc/asterisk/manager.conf': Feb 3 14:38:24 VERBOSE[29434]: == Parsing '/etc/asterisk/manager.conf': Found Feb 3 14:38:24 DEBUG[29434]: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer Feb 3 14:38:24 DEBUG[29434]: ##### Testing 200.196.42.227 with 0.0.0.0 Feb 3 14:38:24 VERBOSE[29434]: == Manager 'bhsoft' logged on from 200.196.42.227 Feb 3 14:38:24 DEBUG[29434]: Manager received command 'queueadd' Feb 3 14:38:24 DEBUG[29434]: Manager received command 'queueadd' Feb 3 14:38:24 DEBUG[29434]: Manager received command 'originate' Feb 3 14:38:24 DEBUG[29434]: Setting NAT on RTP to 4 Feb 3 14:38:24 DEBUG[29434]: Outgoing Call for 3050 Feb 3 14:38:24 DEBUG[29434]: Call from user '3050' is 1 out of 0 Feb 3 14:38:24 DEBUG[29417]: (Provisional) Stopping retransmission (but retaining packet) on '503f9aa6763e9b96429253486b0ebe74@200.196.44.5' Request 102: Found Feb 3 14:38:26 DEBUG[29417]: Acked pending invite 102 Feb 3 14:38:26 DEBUG[29417]: Stopping retransmission on '503f9aa6763e9b96429253486b0ebe74@200.196.44.5' of Request 102: Found Feb 3 14:38:26 DEBUG[29417]: build_route: Contact hop: Feb 3 14:38:26 VERBOSE[29434]: > Channel SIP/3050-d2e1 was answered. Feb 3 14:38:26 DEBUG[29434]: Manager received command 'queuestatus' Feb 3 14:38:26 DEBUG[29434]: Manager received command 'queuestatus' Feb 3 14:38:26 VERBOSE[29435]: -- Executing Answer("SIP/3050-d2e1", "") in new stack Feb 3 14:38:26 VERBOSE[29435]: -- Executing Wait("SIP/3050-d2e1", "1") in new stack Feb 3 14:38:26 DEBUG[29434]: Manager received command 'Status' Feb 3 14:38:27 VERBOSE[29435]: -- Executing SetAMAFlags("SIP/3050-d2e1", "documentation") in new stack Feb 3 14:38:27 VERBOSE[29435]: -- Executing Goto("SIP/3050-d2e1", "100") in new stack Feb 3 14:38:27 VERBOSE[29435]: -- Goto (agente_out,*53,100) Feb 3 14:38:27 VERBOSE[29435]: -- Executing AgentLogin("SIP/3050-d2e1", "8033") in new stack Feb 3 14:38:27 DEBUG[29435]: Ooh, format changed from unknown to alaw Feb 3 14:38:27 DEBUG[29435]: Scheduling timer at 160 sample intervals Feb 3 14:38:27 VERBOSE[29435]: -- Playing 'agent-loginok' (language 'en') Feb 3 14:38:28 DEBUG[29435]: Scheduling timer at 0 sample intervals Feb 3 14:38:28 DEBUG[29435]: Scheduling timer at 0 sample intervals Feb 3 14:38:28 VERBOSE[29435]: -- Started music on hold, class 'silencio', on SIP/3050-d2e1 Feb 3 14:38:28 DEBUG[29435]: Scheduling timer at 160 sample intervals Feb 3 14:38:28 VERBOSE[29435]: -- Agent '8033' logged in (format alaw/slin) Feb 3 14:38:28 DEBUG[29435]: Checking availability of '8033' Feb 3 14:38:28 DEBUG[29435]: Generator got voice, switching to phase locked mode Feb 3 14:38:28 DEBUG[29435]: Scheduling timer at 0 sample intervals Feb 3 14:38:38 DEBUG[29432]: Manager received command 'originate' Feb 3 14:38:38 VERBOSE[29437]: -- Executing Goto("Local/033797922@agente_out-8a8b,2", "disca|033797922|1") in new stack Feb 3 14:38:38 VERBOSE[29437]: -- Goto (disca,033797922,1) Feb 3 14:38:38 VERBOSE[29437]: -- Executing Dial("Local/033797922@agente_out-8a8b,2", "ZAP/g1/7922") in new stack Feb 3 14:38:38 DEBUG[29437]: Dialing '7922' Feb 3 14:38:38 DEBUG[29437]: Deferring dialing... Feb 3 14:38:38 VERBOSE[29437]: -- Called g1/7922 Feb 3 14:38:39 DEBUG[29437]: Exception on 31, channel 1 Feb 3 14:38:39 DEBUG[29437]: Got event Hook Transition Complete(12) on channel 1 (index 0) Feb 3 14:38:40 DEBUG[29437]: Exception on 31, channel 1 Feb 3 14:38:40 DEBUG[29437]: Got event Dial Complete(9) on channel 1 (index 0) Feb 3 14:38:40 DEBUG[29437]: Enabled echo cancellation on channel 1 Feb 3 14:38:40 DEBUG[29437]: Dropping duplicate answer! Feb 3 14:38:40 VERBOSE[29437]: -- Zap/1-1 answered Local/033797922@agente_out-8a8b,2 Feb 3 14:38:40 VERBOSE[29436]: > Channel Local/033797922@agente_out-8a8b,1 was answered. Feb 3 14:38:40 DEBUG[29437]: Planning to masquerade Zap/1-1 into the structure of Local/033797922@agente_out-8a8b,1 Feb 3 14:38:40 DEBUG[29437]: Done planning to masquerade Local/033797922@agente_out-8a8b,1 into the structure of Zap/1-1 Feb 3 14:38:40 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:40 VERBOSE[29438]: -- Executing Dial("Local/033797922@agente_out-8a8b,1", "Agent/8031") in new stack Feb 3 14:38:40 VERBOSE[29438]: -- Stopped music on hold on SIP/3052-2db0 Feb 3 14:38:40 DEBUG[29438]: Scheduling timer at 0 sample intervals Feb 3 14:38:40 VERBOSE[29438]: -- agent_call, call to agent '8031' call on 'SIP/3052-2db0' Feb 3 14:38:40 DEBUG[29438]: Playing beep, lang 'en' Feb 3 14:38:40 DEBUG[29438]: Scheduling timer at 160 sample intervals Feb 3 14:38:40 VERBOSE[29438]: -- Playing 'beep' (language 'en') Feb 3 14:38:40 DEBUG[29438]: Played beep, result '0' Feb 3 14:38:40 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:40 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:40 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:40 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:40 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:40 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:40 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:40 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:40 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29437]: Not posting to queue since already masked on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 DEBUG[29438]: Scheduling timer at 0 sample intervals Feb 3 14:38:41 DEBUG[29438]: Scheduling timer at 0 sample intervals Feb 3 14:38:41 DEBUG[29438]: Waited for stream, result '0' Feb 3 14:38:41 DEBUG[29438]: Set read format, result '0' Feb 3 14:38:41 DEBUG[29438]: Set write format, result '0' Feb 3 14:38:41 VERBOSE[29438]: -- Called 8031 Feb 3 14:38:41 DEBUG[29438]: Actually Masquerading Zap/1-1(6) into the structure of Local/033797922@agente_out-8a8b,1(6) Feb 3 14:38:41 DEBUG[29438]: Got clone lock on 'Zap/1-1' at 0x8152ce0 Feb 3 14:38:41 DEBUG[29437]: Didn't get a frame from channel: Local/033797922@agente_out-8a8b,2 Feb 3 14:38:41 DEBUG[29438]: Putting channel Zap/1-1 in 64/8 formats Feb 3 14:38:41 DEBUG[29438]: New owner for channel 1 is Zap/1-1 Feb 3 14:38:41 DEBUG[29438]: Updated conferencing on 1, with 0 conference users Feb 3 14:38:41 DEBUG[29438]: Updated conferencing on 1, with 0 conference users Feb 3 14:38:41 DEBUG[29438]: Released clone lock on 'Local/033797922@agente_out-8a8b,1' Feb 3 14:38:41 DEBUG[29438]: Done Masquerading Zap/1-1 (6) Feb 3 14:38:41 DEBUG[29437]: Bridge stops bridging channels Local/033797922@agente_out-8a8b,2 and Local/033797922@agente_out-8a8b,1 Feb 3 14:38:41 VERBOSE[29438]: -- Agent/8031 answered Zap/1-1 Feb 3 14:38:41 DEBUG[29437]: Exiting with DIALSTATUS=ANSWER. Feb 3 14:38:41 VERBOSE[29437]: == Spawn extension (disca, 033797922, 1) exited non-zero on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:41 VERBOSE[29437]: -- Executing Hangup("Local/033797922@agente_out-8a8b,2", "") in new stack Feb 3 14:38:41 VERBOSE[29437]: == Spawn extension (disca, h, 1) exited non-zero on 'Local/033797922@agente_out-8a8b,2' Feb 3 14:38:53 DEBUG[29432]: Manager received command 'Redirect' Feb 3 14:38:53 DEBUG[29438]: Didn't get a frame from channel: Zap/1-1 Feb 3 14:38:53 DEBUG[29438]: Bridge stops bridging channels Zap/1-1 and Agent/8031 Feb 3 14:38:53 DEBUG[29438]: Hangup called for state Up Feb 3 14:38:53 VERBOSE[29438]: -- Started music on hold, class 'silencio', on SIP/3052-2db0 Feb 3 14:38:53 DEBUG[29438]: Scheduling timer at 160 sample intervals Feb 3 14:38:53 DEBUG[29438]: Exiting with DIALSTATUS=ANSWER. Feb 3 14:38:53 VERBOSE[29438]: == Spawn extension (agente_out, 8033, 0) exited non-zero on 'Zap/1-1' Feb 3 14:38:53 VERBOSE[29438]: -- Executing Dial("Zap/1-1", "Agent/8033") in new stack Feb 3 14:38:53 VERBOSE[29438]: -- Stopped music on hold on SIP/3050-d2e1 Feb 3 14:38:53 DEBUG[29438]: Scheduling timer at 0 sample intervals Feb 3 14:38:53 VERBOSE[29438]: -- agent_call, call to agent '8033' call on 'SIP/3050-d2e1' Feb 3 14:38:53 DEBUG[29438]: Playing beep, lang 'en' Feb 3 14:38:53 DEBUG[29438]: Scheduling timer at 160 sample intervals Feb 3 14:38:53 VERBOSE[29438]: -- Playing 'beep' (language 'en') Feb 3 14:38:53 DEBUG[29438]: Played beep, result '0' Feb 3 14:38:53 DEBUG[29433]: Generator got voice, switching to phase locked mode Feb 3 14:38:53 DEBUG[29433]: Scheduling timer at 0 sample intervals Feb 3 14:38:53 DEBUG[29438]: Scheduling timer at 0 sample intervals Feb 3 14:38:53 DEBUG[29438]: Scheduling timer at 0 sample intervals Feb 3 14:38:53 DEBUG[29438]: Waited for stream, result '0' Feb 3 14:38:53 DEBUG[29438]: Set read format, result '0' Feb 3 14:38:53 DEBUG[29438]: Set write format, result '0' Feb 3 14:38:53 VERBOSE[29438]: -- Called 8033 Feb 3 14:38:53 VERBOSE[29438]: -- Agent/8033 answered Zap/1-1 Feb 3 14:38:54 DEBUG[29433]: Wrapup time expired! Feb 3 14:38:54 DEBUG[29433]: Checking availability of '8031' Feb 3 14:39:01 DEBUG[29438]: Requesting Hangup because the busy tone was detected on channel Zap/1-1 Feb 3 14:39:01 DEBUG[29438]: Got a FRAME_CONTROL (5) frame on channel Zap/1-1 Feb 3 14:39:01 DEBUG[29438]: Bridge stops bridging channels Zap/1-1 and Agent/8033 Feb 3 14:39:01 DEBUG[29438]: Hangup called for state Up Feb 3 14:39:01 VERBOSE[29438]: -- Started music on hold, class 'silencio', on SIP/3050-d2e1 Feb 3 14:39:01 DEBUG[29438]: Scheduling timer at 160 sample intervals Feb 3 14:39:01 DEBUG[29438]: Exiting with DIALSTATUS=ANSWER. Feb 3 14:39:01 VERBOSE[29438]: == Spawn extension (agente_out, 8033, 1) exited non-zero on 'Zap/1-1' Feb 3 14:39:01 DEBUG[29435]: Generator got voice, switching to phase locked mode Feb 3 14:39:01 DEBUG[29435]: Scheduling timer at 0 sample intervals Feb 3 14:39:01 DEBUG[29438]: Hangup: channel: 1 index = 0, normal = 31, callwait = -1, thirdcall = -1 Feb 3 14:39:01 DEBUG[29438]: disabled echo cancellation on channel 1 Feb 3 14:39:01 DEBUG[29438]: Set option TDD MODE, value: OFF(0) on Zap/1-1 Feb 3 14:39:01 DEBUG[29438]: Updated conferencing on 1, with 0 conference users Feb 3 14:39:01 VERBOSE[29438]: -- Hungup 'Zap/1-1' Feb 3 14:39:02 DEBUG[29435]: Wrapup time expired! Feb 3 14:39:02 DEBUG[29435]: Checking availability of '8033' Feb 3 14:39:05 VERBOSE[29439]: -- Starting simple switch on 'Zap/1-1' Feb 3 14:39:06 NOTICE[29439]: Got event 2 (Ring/Answered)... Feb 3 14:39:10 ERROR[29439]: fsk_serie made mylen < 0 (-10) Feb 3 14:39:10 WARNING[29439]: CallerID feed failed: Success Feb 3 14:39:10 WARNING[29439]: CallerID returned with error on channel 'Zap/1-1' Feb 3 14:39:10 VERBOSE[29439]: -- Executing Macro("Zap/1-1", "tronco_faketone_default|1") in new stack Feb 3 14:39:10 VERBOSE[29439]: -- Executing SetVar("Zap/1-1", "TRONCO=1") in new stack Feb 3 14:39:10 VERBOSE[29439]: -- Executing Goto("Zap/1-1", "tronco_faketone_default|s|1") in new stack Feb 3 14:39:10 VERBOSE[29439]: -- Goto (tronco_faketone_default,s,1) Feb 3 14:39:10 VERBOSE[29439]: == Channel 'Zap/1-1' jumping out of macro 'tronco_faketone_default' Feb 3 14:39:10 VERBOSE[29439]: -- Executing DigitTimeout("Zap/1-1", "5") in new stack Feb 3 14:39:10 VERBOSE[29439]: -- Set Digit Timeout to 5 Feb 3 14:39:10 VERBOSE[29439]: -- Executing ResponseTimeout("Zap/1-1", "5") in new stack Feb 3 14:39:10 VERBOSE[29439]: -- Set Response Timeout to 5 Feb 3 14:39:10 VERBOSE[29439]: -- Executing Answer("Zap/1-1", "") in new stack Feb 3 14:39:10 DEBUG[29439]: Took Zap/1-1 off hook Feb 3 14:39:10 DEBUG[29439]: Enabled echo cancellation on channel 1 Feb 3 14:39:10 DEBUG[29439]: No echo training requested Feb 3 14:39:10 VERBOSE[29439]: -- Executing PlayTones("Zap/1-1", "dial") in new stack Feb 3 14:39:10 DEBUG[29439]: Scheduling timer at 160 sample intervals Feb 3 14:39:10 DEBUG[29439]: Generator got voice, switching to phase locked mode Feb 3 14:39:10 DEBUG[29439]: Scheduling timer at 0 sample intervals Feb 3 14:39:12 DEBUG[29439]: DTMF digit: 3 on Zap/1-1 Feb 3 14:39:12 VERBOSE[29439]: -- Invalid extension '3' in context 'tronco_faketone_default' on Zap/1-1 Feb 3 14:39:12 VERBOSE[29439]: == CDR updated on Zap/1-1 Feb 3 14:39:12 VERBOSE[29439]: -- Executing StopPlayTones("Zap/1-1", "") in new stack Feb 3 14:39:12 DEBUG[29439]: Scheduling timer at 0 sample intervals Feb 3 14:39:12 VERBOSE[29439]: -- Executing SetVar("Zap/1-1", "PRIMEIRODIGITO=3") in new stack Feb 3 14:39:12 VERBOSE[29439]: -- Executing Goto("Zap/1-1", "tronco_faketone_aux|s|1") in new stack Feb 3 14:39:12 VERBOSE[29439]: -- Goto (tronco_faketone_aux,s,1) Feb 3 14:39:12 VERBOSE[29439]: -- Executing NoOp("Zap/1-1", "") in new stack Feb 3 14:39:12 DEBUG[29439]: DTMF digit: 0 on Zap/1-1 Feb 3 14:39:12 DEBUG[29439]: DTMF digit: 9 on Zap/1-1 Feb 3 14:39:12 DEBUG[29439]: DTMF digit: 9 on Zap/1-1 Feb 3 14:39:13 DEBUG[29417]: Auto destroying call 'DE7CF6354CF1494F9E6C07F5D610EDF2@gateway.planetarium.com.br' Feb 3 14:39:18 VERBOSE[29439]: == CDR updated on Zap/1-1 Feb 3 14:39:18 VERBOSE[29439]: -- Executing Goto("Zap/1-1", "FXOCH1_out|3099|1") in new stack Feb 3 14:39:18 VERBOSE[29439]: -- Goto (FXOCH1_out,3099,1) Feb 3 14:39:18 DEBUG[29439]: Expression is '1' Feb 3 14:39:18 VERBOSE[29439]: -- Executing GotoIf("Zap/1-1", "1 ? 2:4") in new stack Feb 3 14:39:18 VERBOSE[29439]: -- Goto (FXOCH1_out,3099,2) Feb 3 14:39:18 VERBOSE[29439]: -- Executing SetVar("Zap/1-1", "CHAMADAINTERNA=T") in new stack Feb 3 14:39:18 VERBOSE[29439]: -- Executing SetCIDNum("Zap/1-1", "7922") in new stack Feb 3 14:39:18 VERBOSE[29439]: -- Executing Goto("Zap/1-1", "disca|3099|1") in new stack Feb 3 14:39:18 VERBOSE[29439]: -- Goto (disca,3099,1) Feb 3 14:39:18 VERBOSE[29439]: -- Executing Goto("Zap/1-1", "principal_in|3099|1") in new stack Feb 3 14:39:18 VERBOSE[29439]: -- Goto (principal_in,3099,1) Feb 3 14:39:18 VERBOSE[29439]: -- Executing Goto("Zap/1-1", "fila_suporte|3099|1") in new stack Feb 3 14:39:18 VERBOSE[29439]: -- Goto (fila_suporte,3099,1) Feb 3 14:39:18 VERBOSE[29439]: -- Executing SetLanguage("Zap/1-1", "br") in new stack Feb 3 14:39:18 VERBOSE[29439]: -- Executing Answer("Zap/1-1", "") in new stack Feb 3 14:39:18 VERBOSE[29439]: -- Executing Wait("Zap/1-1", "3") in new stack Feb 3 14:39:18 DEBUG[29417]: Stopping retransmission on '2804f32d08d13ef62fb87b5c47396b7b@200.196.44.5' of Request 102: Found Feb 3 14:39:21 VERBOSE[29439]: -- Executing SetCIDName("Zap/1-1", "Fila suporte - PABX Spress") in new stack Feb 3 14:39:21 VERBOSE[29439]: -- Executing Queue("Zap/1-1", "suporte|tn|||") in new stack Feb 3 14:39:21 DEBUG[29439]: queue: suporte, options: tn, url: , announce: , timeout: 0, priority: 0 Feb 3 14:39:21 VERBOSE[29439]: -- Started music on hold, class 'default', on Zap/1-1 Feb 3 14:39:21 DEBUG[29439]: Scheduling timer at 160 sample intervals Feb 3 14:39:21 VERBOSE[29439]: -- Stopped music on hold on Zap/1-1 Feb 3 14:39:21 DEBUG[29439]: Scheduling timer at 0 sample intervals Feb 3 14:39:21 DEBUG[29439]: Scheduling timer at 160 sample intervals Feb 3 14:39:21 VERBOSE[29439]: -- Playing 'queue-youarenext' (language 'br') Feb 3 14:39:21 DEBUG[29432]: Manager received command 'queuestatus' Feb 3 14:39:21 DEBUG[29434]: Manager received command 'queuestatus' Feb 3 14:39:21 DEBUG[29422]: Manager received command 'queuestatus' Feb 3 14:39:21 DEBUG[29422]: Manager received command 'status' Feb 3 14:39:29 DEBUG[29439]: Scheduling timer at 0 sample intervals Feb 3 14:39:29 DEBUG[29439]: Scheduling timer at 0 sample intervals Feb 3 14:39:29 VERBOSE[29439]: -- Told Zap/1-1 in suporte their queue position (which was 1) Feb 3 14:39:29 DEBUG[29439]: Scheduling timer at 160 sample intervals Feb 3 14:39:29 VERBOSE[29439]: -- Playing 'queue-thankyou' (language 'br') Feb 3 14:39:30 DEBUG[29439]: Scheduling timer at 0 sample intervals Feb 3 14:39:30 DEBUG[29439]: Scheduling timer at 0 sample intervals Feb 3 14:39:30 VERBOSE[29439]: -- Started music on hold, class 'default', on Zap/1-1 Feb 3 14:39:30 DEBUG[29439]: Scheduling timer at 160 sample intervals Feb 3 14:39:30 VERBOSE[29439]: -- Stopped music on hold on SIP/3052-2db0 Feb 3 14:39:30 DEBUG[29439]: Scheduling timer at 0 sample intervals Feb 3 14:39:30 VERBOSE[29439]: -- agent_call, call to agent '8031' call on 'SIP/3052-2db0' Feb 3 14:39:30 DEBUG[29439]: Playing beep, lang 'en' Feb 3 14:39:30 DEBUG[29439]: Scheduling timer at 160 sample intervals Feb 3 14:39:30 VERBOSE[29439]: -- Playing 'beep' (language 'en') Feb 3 14:39:30 DEBUG[29439]: Played beep, result '0' Feb 3 14:39:31 DEBUG[29439]: Scheduling timer at 0 sample intervals Feb 3 14:39:31 DEBUG[29439]: Scheduling timer at 0 sample intervals Feb 3 14:39:31 DEBUG[29439]: Waited for stream, result '0' Feb 3 14:39:31 DEBUG[29439]: Set read format, result '0' Feb 3 14:39:31 DEBUG[29439]: Set write format, result '0' Feb 3 14:39:31 VERBOSE[29439]: -- Called agent/8031 Feb 3 14:39:31 VERBOSE[29439]: -- Agent/8031 answered Zap/1-1 Feb 3 14:39:31 DEBUG[29439]: Set option TONE VERIFY, mode: MUTECONF/MAX(2) on Zap/1-1 Feb 3 14:39:31 VERBOSE[29439]: -- Stopped music on hold on Zap/1-1 Feb 3 14:39:31 DEBUG[29439]: Scheduling timer at 0 sample intervals Feb 3 14:39:31 DEBUG[29432]: Manager received command 'queuestatus' Feb 3 14:39:31 DEBUG[29434]: Manager received command 'queuestatus' Feb 3 14:39:34 DEBUG[29440]: Manager received command 'login' Feb 3 14:39:34 VERBOSE[29440]: == Parsing '/etc/asterisk/manager.conf': Feb 3 14:39:34 VERBOSE[29440]: == Parsing '/etc/asterisk/manager.conf': Found Feb 3 14:39:34 DEBUG[29440]: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer Feb 3 14:39:34 DEBUG[29440]: 200.196.44.23/255.255.255.255/255.255.255.255 appended to acl for peer Feb 3 14:39:34 DEBUG[29440]: ##### Testing 200.196.44.23 with 0.0.0.0 Feb 3 14:39:34 DEBUG[29440]: ##### Testing 200.196.44.23 with 200.196.44.23 Feb 3 14:39:34 VERBOSE[29440]: == Manager 'monitornagios' logged on from 200.196.44.23 Feb 3 14:39:34 DEBUG[29440]: Manager received command 'ZapShowChannels' Feb 3 14:39:34 DEBUG[29440]: Manager received command 'logoff' Feb 3 14:39:34 VERBOSE[29440]: == Manager 'monitornagios' logged off from 200.196.44.23 Feb 3 14:39:34 DEBUG[29432]: Manager received command 'Hangup' Feb 3 14:39:34 DEBUG[29439]: Didn't get a frame from channel: Zap/1-1 Feb 3 14:39:34 DEBUG[29439]: Bridge stops bridging channels Zap/1-1 and Agent/8031 Feb 3 14:39:34 DEBUG[29439]: Hangup called for state Up Feb 3 14:39:34 VERBOSE[29439]: -- Started music on hold, class 'silencio', on SIP/3052-2db0 Feb 3 14:39:34 DEBUG[29439]: Scheduling timer at 160 sample intervals Feb 3 14:39:34 VERBOSE[29439]: == Spawn extension (fila_suporte, 3099, 5) exited non-zero on 'Zap/1-1' Feb 3 14:39:34 DEBUG[29439]: Hangup: channel: 1 index = 0, normal = 31, callwait = -1, thirdcall = -1 Feb 3 14:39:34 DEBUG[29439]: disabled echo cancellation on channel 1 Feb 3 14:39:34 DEBUG[29439]: Set option TDD MODE, value: OFF(0) on Zap/1-1 Feb 3 14:39:34 DEBUG[29439]: Updated conferencing on 1, with 0 conference users Feb 3 14:39:34 VERBOSE[29439]: -- Hungup 'Zap/1-1' Feb 3 14:39:34 DEBUG[29433]: Generator got voice, switching to phase locked mode Feb 3 14:39:34 DEBUG[29433]: Scheduling timer at 0 sample intervals Feb 3 14:39:35 DEBUG[29433]: Wrapup time expired! Feb 3 14:39:35 DEBUG[29433]: Checking availability of '8031' Feb 3 14:39:40 VERBOSE[29441]: -- Starting simple switch on 'Zap/1-1' Feb 3 14:39:41 NOTICE[29441]: Got event 2 (Ring/Answered)... Feb 3 14:39:45 NOTICE[29441]: Got event 2 (Ring/Answered)... Feb 3 14:39:45 VERBOSE[29441]: -- Executing Macro("Zap/1-1", "tronco_faketone_default|1") in new stack Feb 3 14:39:45 VERBOSE[29441]: -- Executing SetVar("Zap/1-1", "TRONCO=1") in new stack Feb 3 14:39:45 VERBOSE[29441]: -- Executing Goto("Zap/1-1", "tronco_faketone_default|s|1") in new stack Feb 3 14:39:45 VERBOSE[29441]: -- Goto (tronco_faketone_default,s,1) Feb 3 14:39:45 VERBOSE[29441]: == Channel 'Zap/1-1' jumping out of macro 'tronco_faketone_default' Feb 3 14:39:45 VERBOSE[29441]: -- Executing DigitTimeout("Zap/1-1", "5") in new stack Feb 3 14:39:45 VERBOSE[29441]: -- Set Digit Timeout to 5 Feb 3 14:39:45 VERBOSE[29441]: -- Executing ResponseTimeout("Zap/1-1", "5") in new stack Feb 3 14:39:45 VERBOSE[29441]: -- Set Response Timeout to 5 Feb 3 14:39:45 VERBOSE[29441]: -- Executing Answer("Zap/1-1", "") in new stack Feb 3 14:39:45 DEBUG[29441]: Took Zap/1-1 off hook Feb 3 14:39:45 DEBUG[29441]: Enabled echo cancellation on channel 1 Feb 3 14:39:45 DEBUG[29441]: No echo training requested Feb 3 14:39:45 VERBOSE[29441]: -- Executing PlayTones("Zap/1-1", "dial") in new stack Feb 3 14:39:45 DEBUG[29441]: Scheduling timer at 160 sample intervals Feb 3 14:39:45 DEBUG[29441]: Generator got voice, switching to phase locked mode Feb 3 14:39:45 DEBUG[29441]: Scheduling timer at 0 sample intervals Feb 3 14:39:46 DEBUG[29441]: DTMF digit: 3 on Zap/1-1 Feb 3 14:39:46 VERBOSE[29441]: -- Invalid extension '3' in context 'tronco_faketone_default' on Zap/1-1 Feb 3 14:39:46 VERBOSE[29441]: == CDR updated on Zap/1-1 Feb 3 14:39:46 VERBOSE[29441]: -- Executing StopPlayTones("Zap/1-1", "") in new stack Feb 3 14:39:46 DEBUG[29441]: Scheduling timer at 0 sample intervals Feb 3 14:39:46 VERBOSE[29441]: -- Executing SetVar("Zap/1-1", "PRIMEIRODIGITO=3") in new stack Feb 3 14:39:46 VERBOSE[29441]: -- Executing Goto("Zap/1-1", "tronco_faketone_aux|s|1") in new stack Feb 3 14:39:46 VERBOSE[29441]: -- Goto (tronco_faketone_aux,s,1) Feb 3 14:39:46 VERBOSE[29441]: -- Executing NoOp("Zap/1-1", "") in new stack Feb 3 14:39:47 DEBUG[29441]: DTMF digit: 0 on Zap/1-1 Feb 3 14:39:47 DEBUG[29441]: DTMF digit: 9 on Zap/1-1 Feb 3 14:39:47 DEBUG[29441]: DTMF digit: 9 on Zap/1-1 Feb 3 14:39:53 VERBOSE[29441]: == CDR updated on Zap/1-1 Feb 3 14:39:53 VERBOSE[29441]: -- Executing Goto("Zap/1-1", "FXOCH1_out|3099|1") in new stack Feb 3 14:39:53 VERBOSE[29441]: -- Goto (FXOCH1_out,3099,1) Feb 3 14:39:53 DEBUG[29441]: Expression is '1' Feb 3 14:39:53 VERBOSE[29441]: -- Executing GotoIf("Zap/1-1", "1 ? 2:4") in new stack Feb 3 14:39:53 VERBOSE[29441]: -- Goto (FXOCH1_out,3099,2) Feb 3 14:39:53 VERBOSE[29441]: -- Executing SetVar("Zap/1-1", "CHAMADAINTERNA=T") in new stack Feb 3 14:39:53 VERBOSE[29441]: -- Executing SetCIDNum("Zap/1-1", "7922") in new stack Feb 3 14:39:53 VERBOSE[29441]: -- Executing Goto("Zap/1-1", "disca|3099|1") in new stack Feb 3 14:39:53 VERBOSE[29441]: -- Goto (disca,3099,1) Feb 3 14:39:53 VERBOSE[29441]: -- Executing Goto("Zap/1-1", "principal_in|3099|1") in new stack Feb 3 14:39:53 VERBOSE[29441]: -- Goto (principal_in,3099,1) Feb 3 14:39:53 VERBOSE[29441]: -- Executing Goto("Zap/1-1", "fila_suporte|3099|1") in new stack Feb 3 14:39:53 VERBOSE[29441]: -- Goto (fila_suporte,3099,1) Feb 3 14:39:53 VERBOSE[29441]: -- Executing SetLanguage("Zap/1-1", "br") in new stack Feb 3 14:39:53 VERBOSE[29441]: -- Executing Answer("Zap/1-1", "") in new stack Feb 3 14:39:53 VERBOSE[29441]: -- Executing Wait("Zap/1-1", "3") in new stack Feb 3 14:39:56 VERBOSE[29441]: -- Executing SetCIDName("Zap/1-1", "Fila suporte - PABX Spress") in new stack Feb 3 14:39:56 VERBOSE[29441]: -- Executing Queue("Zap/1-1", "suporte|tn|||") in new stack Feb 3 14:39:56 DEBUG[29441]: queue: suporte, options: tn, url: , announce: , timeout: 0, priority: 0 Feb 3 14:39:56 VERBOSE[29441]: -- Started music on hold, class 'default', on Zap/1-1 Feb 3 14:39:56 DEBUG[29441]: Scheduling timer at 160 sample intervals Feb 3 14:39:56 VERBOSE[29441]: -- Stopped music on hold on Zap/1-1 Feb 3 14:39:56 DEBUG[29441]: Scheduling timer at 0 sample intervals Feb 3 14:39:56 DEBUG[29441]: Scheduling timer at 160 sample intervals Feb 3 14:39:56 VERBOSE[29441]: -- Playing 'queue-youarenext' (language 'br') Feb 3 14:39:56 DEBUG[29432]: Manager received command 'queuestatus' Feb 3 14:39:56 DEBUG[29434]: Manager received command 'queuestatus' Feb 3 14:39:56 DEBUG[29422]: Manager received command 'queuestatus' Feb 3 14:39:56 DEBUG[29422]: Manager received command 'status' Feb 3 14:40:04 DEBUG[29441]: Scheduling timer at 0 sample intervals Feb 3 14:40:04 DEBUG[29441]: Scheduling timer at 0 sample intervals Feb 3 14:40:04 VERBOSE[29441]: -- Told Zap/1-1 in suporte their queue position (which was 1) Feb 3 14:40:04 DEBUG[29441]: Scheduling timer at 160 sample intervals Feb 3 14:40:04 VERBOSE[29441]: -- Playing 'queue-thankyou' (language 'br') Feb 3 14:40:05 DEBUG[29441]: Scheduling timer at 0 sample intervals Feb 3 14:40:05 DEBUG[29441]: Scheduling timer at 0 sample intervals Feb 3 14:40:05 VERBOSE[29441]: -- Started music on hold, class 'default', on Zap/1-1 Feb 3 14:40:05 DEBUG[29441]: Scheduling timer at 160 sample intervals Feb 3 14:40:05 VERBOSE[29441]: -- Stopped music on hold on SIP/3050-d2e1 Feb 3 14:40:05 DEBUG[29441]: Scheduling timer at 0 sample intervals Feb 3 14:40:05 VERBOSE[29441]: -- agent_call, call to agent '8033' call on 'SIP/3050-d2e1' Feb 3 14:40:05 DEBUG[29441]: Playing beep, lang 'en' Feb 3 14:40:05 DEBUG[29441]: Scheduling timer at 160 sample intervals Feb 3 14:40:05 VERBOSE[29441]: -- Playing 'beep' (language 'en') Feb 3 14:40:05 DEBUG[29441]: Played beep, result '0' Feb 3 14:40:06 DEBUG[29441]: Scheduling timer at 0 sample intervals Feb 3 14:40:06 DEBUG[29441]: Scheduling timer at 0 sample intervals Feb 3 14:40:06 DEBUG[29441]: Waited for stream, result '0' Feb 3 14:40:06 DEBUG[29441]: Set read format, result '0' Feb 3 14:40:06 DEBUG[29441]: Set write format, result '0' Feb 3 14:40:06 VERBOSE[29441]: -- Called agent/8033 Feb 3 14:40:06 VERBOSE[29441]: -- Agent/8033 answered Zap/1-1 Feb 3 14:40:06 DEBUG[29441]: Set option TONE VERIFY, mode: MUTECONF/MAX(2) on Zap/1-1 Feb 3 14:40:06 VERBOSE[29441]: -- Stopped music on hold on Zap/1-1 Feb 3 14:40:06 DEBUG[29441]: Scheduling timer at 0 sample intervals Feb 3 14:40:06 DEBUG[29432]: Manager received command 'queuestatus' Feb 3 14:40:06 DEBUG[29434]: Manager received command 'queuestatus' Feb 3 14:40:13 DEBUG[29441]: Requesting Hangup because the busy tone was detected on channel Zap/1-1 Feb 3 14:40:13 DEBUG[29441]: Didn't get a frame from channel: Zap/1-1 Feb 3 14:40:13 DEBUG[29441]: Bridge stops bridging channels Zap/1-1 and Agent/8033 Feb 3 14:40:13 DEBUG[29441]: Hangup called for state Up Feb 3 14:40:13 VERBOSE[29441]: -- Started music on hold, class 'silencio', on SIP/3050-d2e1 Feb 3 14:40:13 DEBUG[29441]: Scheduling timer at 160 sample intervals Feb 3 14:40:13 VERBOSE[29441]: == Spawn extension (fila_suporte, 3099, 5) exited non-zero on 'Zap/1-1' Feb 3 14:40:13 DEBUG[29435]: Generator got voice, switching to phase locked mode Feb 3 14:40:13 DEBUG[29435]: Scheduling timer at 0 sample intervals Feb 3 14:40:13 DEBUG[29441]: Hangup: channel: 1 index = 0, normal = 31, callwait = -1, thirdcall = -1 Feb 3 14:40:13 DEBUG[29441]: disabled echo cancellation on channel 1 Feb 3 14:40:13 DEBUG[29441]: Set option TDD MODE, value: OFF(0) on Zap/1-1 Feb 3 14:40:13 DEBUG[29441]: Updated conferencing on 1, with 0 conference users Feb 3 14:40:13 VERBOSE[29441]: -- Hungup 'Zap/1-1' Feb 3 14:40:14 DEBUG[29435]: Wrapup time expired! Feb 3 14:40:14 DEBUG[29435]: Checking availability of '8033' Feb 3 14:40:18 DEBUG[29417]: Stopping retransmission on '2388ad1436437bc80569f971384c277a@200.196.44.5' of Request 102: Found Feb 3 14:40:20 DEBUG[29432]: Manager received command 'QueueRemove' Feb 3 14:40:20 DEBUG[29432]: Manager received command 'QueueRemove' Feb 3 14:40:20 DEBUG[29432]: Manager received command 'Hangup' Feb 3 14:40:20 VERBOSE[29432]: == Manager 'bhsoft' logged off from 200.196.42.227 Feb 3 14:40:20 VERBOSE[29433]: -- Stopped music on hold on SIP/3052-2db0 Feb 3 14:40:20 DEBUG[29433]: Scheduling timer at 0 sample intervals Feb 3 14:40:20 VERBOSE[29433]: -- Agent '8031' logged out Feb 3 14:40:20 VERBOSE[29433]: == Spawn extension (agente_out, *53, 100) exited non-zero on 'SIP/3052-2db0' Feb 3 14:40:20 DEBUG[29433]: update_user_counter(3052) - decrement outUse counter Feb 3 14:40:20 DEBUG[29417]: Stopping retransmission on '43fd588943dd0a2e01b288567b6f3b78@200.196.44.5' of Request 103: Found Feb 3 14:40:29 DEBUG[29434]: Manager received command 'originate' Feb 3 14:40:29 DEBUG[29460]: Expression is '1' Feb 3 14:40:29 VERBOSE[29460]: -- Executing GotoIf("Local/3052@agente_out-abdb,2", "1 ? 2:4") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Goto (agente_out,3052,2) Feb 3 14:40:29 VERBOSE[29460]: -- Executing SetVar("Local/3052@agente_out-abdb,2", "CHAMADAINTERNA=T") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Executing SetCIDNum("Local/3052@agente_out-abdb,2", "3050") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Executing Goto("Local/3052@agente_out-abdb,2", "disca|3052|1") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Goto (disca,3052,1) Feb 3 14:40:29 VERBOSE[29460]: -- Executing Goto("Local/3052@agente_out-abdb,2", "principal_in|3052|1") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Goto (principal_in,3052,1) Feb 3 14:40:29 VERBOSE[29460]: -- Executing Goto("Local/3052@agente_out-abdb,2", "3052_in|3052|1") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Goto (3052_in,3052,1) Feb 3 14:40:29 VERBOSE[29460]: -- Executing Goto("Local/3052@agente_out-abdb,2", "1000") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Goto (3052_in,3052,1000) Feb 3 14:40:29 VERBOSE[29460]: -- Executing Macro("Local/3052@agente_out-abdb,2", "atende|SIP/3052|3052") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Executing SetLanguage("Local/3052@agente_out-abdb,2", "br") in new stack Feb 3 14:40:29 DEBUG[29460]: Expression is '1' Feb 3 14:40:29 VERBOSE[29460]: -- Executing GotoIf("Local/3052@agente_out-abdb,2", "1 ? 3:4") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Goto (macro-atende,s,3) Feb 3 14:40:29 VERBOSE[29460]: -- Executing LookupCIDName("Local/3052@agente_out-abdb,2", "") in new stack Feb 3 14:40:29 DEBUG[29460]: Unable to find key '3050' in family 'cidname' Feb 3 14:40:29 VERBOSE[29460]: -- Executing LookupBlacklist("Local/3052@agente_out-abdb,2", "") in new stack Feb 3 14:40:29 DEBUG[29460]: Unable to find key '3050' in family 'blacklist' Feb 3 14:40:29 DEBUG[29460]: Unable to find key '(null)' in family 'blacklist' Feb 3 14:40:29 VERBOSE[29460]: -- Executing DBget("Local/3052@agente_out-abdb,2", "RAMALREDIR=SIGAME/3052") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- DBget: varname=RAMALREDIR, family=SIGAME, key=3052 Feb 3 14:40:29 DEBUG[29460]: Unable to find key '3052' in family 'SIGAME' Feb 3 14:40:29 VERBOSE[29460]: -- DBget: Value not found in database. Feb 3 14:40:29 VERBOSE[29460]: -- Executing Goto("Local/3052@agente_out-abdb,2", "s|8") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Goto (macro-atende,s,8) Feb 3 14:40:29 VERBOSE[29460]: -- Executing SetVar("Local/3052@agente_out-abdb,2", "RAMALFINAL=3052") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Executing DBput("Local/3052@agente_out-abdb,2", "ULTIMOCHAMADO/3052=3050") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- DBput: family=ULTIMOCHAMADO, key=3052, value=3050 Feb 3 14:40:29 VERBOSE[29460]: -- Executing SetGroup("Local/3052@agente_out-abdb,2", "3052") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Executing DBget("Local/3052@agente_out-abdb,2", "MAXLIGACOES=MAXLIGACOES/3052") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- DBget: varname=MAXLIGACOES, family=MAXLIGACOES, key=3052 Feb 3 14:40:29 DEBUG[29460]: Unable to find key '3052' in family 'MAXLIGACOES' Feb 3 14:40:29 VERBOSE[29460]: -- DBget: Value not found in database. Feb 3 14:40:29 VERBOSE[29460]: -- Executing Goto("Local/3052@agente_out-abdb,2", "s|13") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Goto (macro-atende,s,13) Feb 3 14:40:29 VERBOSE[29460]: -- Executing StopMonitor("Local/3052@agente_out-abdb,2", "") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Executing DBget("Local/3052@agente_out-abdb,2", "GRAVACAOCHAMADA=GRAVACAOCHAMADA/3052") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- DBget: varname=GRAVACAOCHAMADA, family=GRAVACAOCHAMADA, key=3052 Feb 3 14:40:29 DEBUG[29460]: Unable to find key '3052' in family 'GRAVACAOCHAMADA' Feb 3 14:40:29 VERBOSE[29460]: -- DBget: Value not found in database. Feb 3 14:40:29 VERBOSE[29460]: -- Executing Goto("Local/3052@agente_out-abdb,2", "s|18") in new stack Feb 3 14:40:29 VERBOSE[29460]: -- Goto (macro-atende,s,18) Feb 3 14:40:29 VERBOSE[29460]: -- Executing Dial("Local/3052@agente_out-abdb,2", "SIP/3052|120|T") in new stack Feb 3 14:40:29 DEBUG[29460]: SIMPLE DIAL (NO URL) Feb 3 14:40:29 DEBUG[29460]: Setting NAT on RTP to 0 Feb 3 14:40:29 DEBUG[29460]: Outgoing Call for 3052 Feb 3 14:40:29 DEBUG[29460]: Call from user '3052' is 1 out of 0 Feb 3 14:40:29 VERBOSE[29460]: -- Called 3052 Feb 3 14:40:29 DEBUG[29417]: (Provisional) Stopping retransmission (but retaining packet) on '2c97275e5b590eaa4d1a82826be0ee86@200.196.44.5' Request 102: Found Feb 3 14:40:29 DEBUG[29417]: (Provisional) Stopping retransmission (but retaining packet) on '2c97275e5b590eaa4d1a82826be0ee86@200.196.44.5' Request 102: Found Feb 3 14:40:29 VERBOSE[29460]: -- SIP/3052-b06c is ringing Feb 3 14:40:32 DEBUG[29417]: Acked pending invite 102 Feb 3 14:40:32 DEBUG[29417]: Stopping retransmission on '2c97275e5b590eaa4d1a82826be0ee86@200.196.44.5' of Request 102: Found Feb 3 14:40:32 DEBUG[29417]: build_route: Contact hop: Feb 3 14:40:32 VERBOSE[29460]: -- SIP/3052-b06c answered Local/3052@agente_out-abdb,2 Feb 3 14:40:32 VERBOSE[29459]: > Channel Local/3052@agente_out-abdb,1 was answered. Feb 3 14:40:32 VERBOSE[29461]: -- Executing Dial("Local/3052@agente_out-abdb,1", "Agent/8033") in new stack Feb 3 14:40:32 VERBOSE[29461]: -- Stopped music on hold on SIP/3050-d2e1 Feb 3 14:40:32 DEBUG[29461]: Scheduling timer at 0 sample intervals Feb 3 14:40:32 VERBOSE[29461]: -- agent_call, call to agent '8033' call on 'SIP/3050-d2e1' Feb 3 14:40:32 DEBUG[29461]: Playing beep, lang 'en' Feb 3 14:40:32 DEBUG[29461]: Scheduling timer at 160 sample intervals Feb 3 14:40:32 VERBOSE[29461]: -- Playing 'beep' (language 'en') Feb 3 14:40:32 DEBUG[29461]: Played beep, result '0' Feb 3 14:40:32 DEBUG[29460]: Planning to masquerade SIP/3052-b06c into the structure of Local/3052@agente_out-abdb,1 Feb 3 14:40:32 DEBUG[29460]: Done planning to masquerade Local/3052@agente_out-abdb,1 into the structure of SIP/3052-b06c Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29460]: Not posting to queue since already masked on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29461]: Scheduling timer at 0 sample intervals Feb 3 14:40:32 DEBUG[29461]: Scheduling timer at 0 sample intervals Feb 3 14:40:32 DEBUG[29461]: Waited for stream, result '0' Feb 3 14:40:32 DEBUG[29461]: Set read format, result '0' Feb 3 14:40:32 DEBUG[29461]: Set write format, result '0' Feb 3 14:40:32 VERBOSE[29461]: -- Called 8033 Feb 3 14:40:32 DEBUG[29461]: Actually Masquerading SIP/3052-b06c(6) into the structure of Local/3052@agente_out-abdb,1(6) Feb 3 14:40:32 DEBUG[29461]: Got clone lock on 'SIP/3052-b06c' at 0x8152c80 Feb 3 14:40:32 DEBUG[29460]: Didn't get a frame from channel: Local/3052@agente_out-abdb,2 Feb 3 14:40:32 DEBUG[29461]: Putting channel SIP/3052-b06c in 64/8 formats Feb 3 14:40:32 DEBUG[29461]: Released clone lock on 'Local/3052@agente_out-abdb,1' Feb 3 14:40:32 DEBUG[29461]: Done Masquerading SIP/3052-b06c (6) Feb 3 14:40:32 DEBUG[29460]: Bridge stops bridging channels Local/3052@agente_out-abdb,2 and Local/3052@agente_out-abdb,1 Feb 3 14:40:32 VERBOSE[29461]: -- Agent/8033 answered SIP/3052-b06c Feb 3 14:40:32 DEBUG[29460]: Exiting with DIALSTATUS=ANSWER. Feb 3 14:40:32 VERBOSE[29460]: == Spawn extension (macro-atende, s, 18) exited non-zero on 'Local/3052@agente_out-abdb,2' in macro 'atende' Feb 3 14:40:32 VERBOSE[29460]: == Spawn extension (3052_in, 3052, 1000) exited non-zero on 'Local/3052@agente_out-abdb,2' Feb 3 14:40:32 DEBUG[29461]: Ooh, format changed from unknown to alaw Feb 3 14:40:34 DEBUG[29417]: Auto destroying call 'DE7CF6354CF1494F9E6C07F5D610EDF2@gateway.planetarium.com.br' Feb 3 14:40:38 DEBUG[29434]: Manager received command 'Hangup' Feb 3 14:40:38 DEBUG[29461]: Didn't get a frame from channel: Agent/8033 Feb 3 14:40:38 DEBUG[29461]: Bridge stops bridging channels SIP/3052-b06c and Agent/8033 Feb 3 14:40:38 DEBUG[29461]: Hangup called for state Up Feb 3 14:40:38 VERBOSE[29461]: -- Started music on hold, class 'silencio', on SIP/3050-d2e1 Feb 3 14:40:38 DEBUG[29461]: Scheduling timer at 160 sample intervals Feb 3 14:40:38 DEBUG[29461]: Exiting with DIALSTATUS=ANSWER. Feb 3 14:40:38 VERBOSE[29461]: == Spawn extension (agente_out, 8033, 1) exited non-zero on 'SIP/3052-b06c' Feb 3 14:40:38 DEBUG[29461]: update_user_counter(3052) - decrement outUse counter Feb 3 14:40:38 DEBUG[29435]: Generator got voice, switching to phase locked mode Feb 3 14:40:38 DEBUG[29435]: Scheduling timer at 0 sample intervals Feb 3 14:40:38 DEBUG[29417]: Stopping retransmission on '2c97275e5b590eaa4d1a82826be0ee86@200.196.44.5' of Request 103: Found Feb 3 14:40:39 DEBUG[29435]: Wrapup time expired! Feb 3 14:40:39 DEBUG[29435]: Checking availability of '8033' Feb 3 14:40:47 DEBUG[29434]: Manager received command 'originate' Feb 3 14:40:47 VERBOSE[29463]: -- Executing Goto("Local/033797922@agente_out-ba2a,2", "disca|033797922|1") in new stack Feb 3 14:40:47 VERBOSE[29463]: -- Goto (disca,033797922,1) Feb 3 14:40:47 VERBOSE[29463]: -- Executing Dial("Local/033797922@agente_out-ba2a,2", "ZAP/g1/7922") in new stack Feb 3 14:40:47 DEBUG[29463]: Dialing '7922' Feb 3 14:40:47 DEBUG[29463]: Deferring dialing... Feb 3 14:40:47 VERBOSE[29463]: -- Called g1/7922 Feb 3 14:40:48 DEBUG[29463]: Exception on 31, channel 1 Feb 3 14:40:48 DEBUG[29463]: Got event Hook Transition Complete(12) on channel 1 (index 0) Feb 3 14:40:49 DEBUG[29463]: Exception on 31, channel 1 Feb 3 14:40:49 DEBUG[29463]: Got event Dial Complete(9) on channel 1 (index 0) Feb 3 14:40:49 DEBUG[29463]: Enabled echo cancellation on channel 1 Feb 3 14:40:49 DEBUG[29463]: Dropping duplicate answer! Feb 3 14:40:49 VERBOSE[29463]: -- Zap/1-1 answered Local/033797922@agente_out-ba2a,2 Feb 3 14:40:49 VERBOSE[29462]: > Channel Local/033797922@agente_out-ba2a,1 was answered. Feb 3 14:40:49 VERBOSE[29464]: -- Executing Dial("Local/033797922@agente_out-ba2a,1", "Agent/8033") in new stack Feb 3 14:40:49 VERBOSE[29464]: -- Stopped music on hold on SIP/3050-d2e1 Feb 3 14:40:49 DEBUG[29464]: Scheduling timer at 0 sample intervals Feb 3 14:40:49 VERBOSE[29464]: -- agent_call, call to agent '8033' call on 'SIP/3050-d2e1' Feb 3 14:40:49 DEBUG[29464]: Playing beep, lang 'en' Feb 3 14:40:49 DEBUG[29464]: Scheduling timer at 160 sample intervals Feb 3 14:40:49 VERBOSE[29464]: -- Playing 'beep' (language 'en') Feb 3 14:40:49 DEBUG[29464]: Played beep, result '0' Feb 3 14:40:50 DEBUG[29464]: Scheduling timer at 0 sample intervals Feb 3 14:40:50 DEBUG[29464]: Scheduling timer at 0 sample intervals Feb 3 14:40:50 DEBUG[29464]: Waited for stream, result '0' Feb 3 14:40:50 DEBUG[29464]: Set read format, result '0' Feb 3 14:40:50 DEBUG[29464]: Set write format, result '0' Feb 3 14:40:50 VERBOSE[29464]: -- Called 8033 Feb 3 14:40:50 VERBOSE[29464]: -- Agent/8033 answered Local/033797922@agente_out-ba2a,1 Feb 3 14:40:50 DEBUG[29463]: Planning to masquerade Zap/1-1 into the structure of Local/033797922@agente_out-ba2a,1 Feb 3 14:40:50 DEBUG[29463]: Done planning to masquerade Local/033797922@agente_out-ba2a,1 into the structure of Zap/1-1 Feb 3 14:40:50 DEBUG[29463]: Not posting to queue since already masked on 'Local/033797922@agente_out-ba2a,2' Feb 3 14:40:50 DEBUG[29464]: Actually Masquerading Zap/1-1(6) into the structure of Local/033797922@agente_out-ba2a,1(6) Feb 3 14:40:50 DEBUG[29464]: Got clone lock on 'Zap/1-1' at 0x8156a98 Feb 3 14:40:50 DEBUG[29463]: Didn't get a frame from channel: Local/033797922@agente_out-ba2a,2 Feb 3 14:40:50 DEBUG[29464]: Putting channel Zap/1-1 in 64/8 formats Feb 3 14:40:50 DEBUG[29464]: New owner for channel 1 is Zap/1-1 Feb 3 14:40:50 DEBUG[29463]: Bridge stops bridging channels Local/033797922@agente_out-ba2a,2 and Local/033797922@agente_out-ba2a,1 Feb 3 14:40:50 DEBUG[29464]: Updated conferencing on 1, with 0 conference users Feb 3 14:40:50 DEBUG[29464]: Updated conferencing on 1, with 0 conference users Feb 3 14:40:50 DEBUG[29464]: Released clone lock on 'Local/033797922@agente_out-ba2a,1' Feb 3 14:40:50 DEBUG[29464]: Done Masquerading Zap/1-1 (6) Feb 3 14:40:50 DEBUG[29463]: Exiting with DIALSTATUS=ANSWER. Feb 3 14:40:50 VERBOSE[29463]: == Spawn extension (disca, 033797922, 1) exited non-zero on 'Local/033797922@agente_out-ba2a,2' Feb 3 14:40:50 VERBOSE[29463]: -- Executing Hangup("Local/033797922@agente_out-ba2a,2", "") in new stack Feb 3 14:40:50 VERBOSE[29463]: == Spawn extension (disca, h, 1) exited non-zero on 'Local/033797922@agente_out-ba2a,2' Feb 3 14:40:56 DEBUG[29464]: Requesting Hangup because the busy tone was detected on channel Zap/1-1 Feb 3 14:40:56 DEBUG[29464]: Got a FRAME_CONTROL (5) frame on channel Zap/1-1 Feb 3 14:40:56 DEBUG[29464]: Bridge stops bridging channels Zap/1-1 and Agent/8033 Feb 3 14:40:56 DEBUG[29464]: Hangup called for state Up Feb 3 14:40:56 VERBOSE[29464]: -- Started music on hold, class 'silencio', on SIP/3050-d2e1 Feb 3 14:40:56 DEBUG[29464]: Scheduling timer at 160 sample intervals Feb 3 14:40:56 DEBUG[29464]: Exiting with DIALSTATUS=ANSWER. Feb 3 14:40:56 VERBOSE[29464]: == Spawn extension (agente_out, 8033, 1) exited non-zero on 'Zap/1-1' Feb 3 14:40:56 DEBUG[29464]: Hangup: channel: 1 index = 0, normal = 31, callwait = -1, thirdcall = -1 Feb 3 14:40:56 DEBUG[29464]: disabled echo cancellation on channel 1 Feb 3 14:40:56 DEBUG[29464]: Set option TDD MODE, value: OFF(0) on Zap/1-1 Feb 3 14:40:56 DEBUG[29464]: Updated conferencing on 1, with 0 conference users Feb 3 14:40:56 VERBOSE[29464]: -- Hungup 'Zap/1-1' Feb 3 14:40:56 DEBUG[29435]: Generator got voice, switching to phase locked mode Feb 3 14:40:56 DEBUG[29435]: Scheduling timer at 0 sample intervals Feb 3 14:40:57 DEBUG[29435]: Wrapup time expired! Feb 3 14:40:57 DEBUG[29435]: Checking availability of '8033' Feb 3 14:41:01 DEBUG[29465]: Manager received command 'login' Feb 3 14:41:01 VERBOSE[29465]: == Parsing '/etc/asterisk/manager.conf': Feb 3 14:41:01 VERBOSE[29465]: == Parsing '/etc/asterisk/manager.conf': Found Feb 3 14:41:01 DEBUG[29465]: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer Feb 3 14:41:01 DEBUG[29465]: ##### Testing 200.196.42.227 with 0.0.0.0 Feb 3 14:41:01 VERBOSE[29465]: == Manager 'bhsoft' logged on from 200.196.42.227 Feb 3 14:41:02 DEBUG[29465]: Manager received command 'queueadd' Feb 3 14:41:02 DEBUG[29465]: Manager received command 'queueadd' Feb 3 14:41:02 DEBUG[29465]: Manager received command 'originate' Feb 3 14:41:02 DEBUG[29465]: Setting NAT on RTP to 0 Feb 3 14:41:02 DEBUG[29465]: Outgoing Call for 3052 Feb 3 14:41:02 DEBUG[29465]: Call from user '3052' is 1 out of 0 Feb 3 14:41:02 DEBUG[29417]: (Provisional) Stopping retransmission (but retaining packet) on '0a0585936c52b11140d162e84e14f871@200.196.44.5' Request 102: Found Feb 3 14:41:02 DEBUG[29417]: (Provisional) Stopping retransmission (but retaining packet) on '0a0585936c52b11140d162e84e14f871@200.196.44.5' Request 102: Found Feb 3 14:41:04 DEBUG[29417]: Acked pending invite 102 Feb 3 14:41:04 DEBUG[29417]: Stopping retransmission on '0a0585936c52b11140d162e84e14f871@200.196.44.5' of Request 102: Found Feb 3 14:41:04 DEBUG[29417]: build_route: Contact hop: Feb 3 14:41:04 VERBOSE[29465]: > Channel SIP/3052-1ef2 was answered. Feb 3 14:41:04 DEBUG[29465]: Manager received command 'queuestatus' Feb 3 14:41:04 DEBUG[29465]: Manager received command 'queuestatus' Feb 3 14:41:04 VERBOSE[29466]: -- Executing Answer("SIP/3052-1ef2", "") in new stack Feb 3 14:41:04 VERBOSE[29466]: -- Executing Wait("SIP/3052-1ef2", "1") in new stack Feb 3 14:41:04 DEBUG[29465]: Manager received command 'Status' Feb 3 14:41:05 VERBOSE[29466]: -- Executing SetAMAFlags("SIP/3052-1ef2", "documentation") in new stack Feb 3 14:41:05 VERBOSE[29466]: -- Executing Goto("SIP/3052-1ef2", "100") in new stack Feb 3 14:41:05 VERBOSE[29466]: -- Goto (agente_out,*53,100) Feb 3 14:41:05 VERBOSE[29466]: -- Executing AgentLogin("SIP/3052-1ef2", "8031") in new stack Feb 3 14:41:05 DEBUG[29466]: Ooh, format changed from unknown to alaw Feb 3 14:41:05 DEBUG[29466]: Scheduling timer at 160 sample intervals Feb 3 14:41:05 VERBOSE[29466]: -- Playing 'agent-loginok' (language 'en') Feb 3 14:41:06 DEBUG[29466]: Scheduling timer at 0 sample intervals Feb 3 14:41:06 DEBUG[29466]: Scheduling timer at 0 sample intervals Feb 3 14:41:06 VERBOSE[29466]: -- Started music on hold, class 'silencio', on SIP/3052-1ef2 Feb 3 14:41:06 DEBUG[29466]: Scheduling timer at 160 sample intervals Feb 3 14:41:06 VERBOSE[29466]: -- Agent '8031' logged in (format alaw/slin) Feb 3 14:41:06 DEBUG[29466]: Checking availability of '8031' Feb 3 14:41:06 DEBUG[29466]: Generator got voice, switching to phase locked mode Feb 3 14:41:06 DEBUG[29466]: Scheduling timer at 0 sample intervals Feb 3 14:41:10 DEBUG[29465]: Manager received command 'originate' Feb 3 14:41:10 VERBOSE[29468]: -- Executing Goto("Local/033797922@agente_out-63aa,2", "disca|033797922|1") in new stack Feb 3 14:41:10 VERBOSE[29468]: -- Goto (disca,033797922,1) Feb 3 14:41:10 VERBOSE[29468]: -- Executing Dial("Local/033797922@agente_out-63aa,2", "ZAP/g1/7922") in new stack Feb 3 14:41:10 DEBUG[29468]: Dialing '7922' Feb 3 14:41:10 DEBUG[29468]: Deferring dialing... Feb 3 14:41:10 VERBOSE[29468]: -- Called g1/7922 Feb 3 14:41:11 DEBUG[29468]: Exception on 31, channel 1 Feb 3 14:41:11 DEBUG[29468]: Got event Hook Transition Complete(12) on channel 1 (index 0) Feb 3 14:41:12 DEBUG[29468]: Exception on 31, channel 1 Feb 3 14:41:12 DEBUG[29468]: Got event Dial Complete(9) on channel 1 (index 0) Feb 3 14:41:12 DEBUG[29468]: Enabled echo cancellation on channel 1 Feb 3 14:41:12 DEBUG[29468]: Dropping duplicate answer! Feb 3 14:41:12 VERBOSE[29468]: -- Zap/1-1 answered Local/033797922@agente_out-63aa,2 Feb 3 14:41:12 VERBOSE[29467]: > Channel Local/033797922@agente_out-63aa,1 was answered. Feb 3 14:41:12 DEBUG[29468]: Planning to masquerade Zap/1-1 into the structure of Local/033797922@agente_out-63aa,1 Feb 3 14:41:12 DEBUG[29468]: Done planning to masquerade Local/033797922@agente_out-63aa,1 into the structure of Zap/1-1 Feb 3 14:41:12 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:12 VERBOSE[29469]: -- Executing Dial("Local/033797922@agente_out-63aa,1", "Agent/8031") in new stack Feb 3 14:41:12 VERBOSE[29469]: -- Stopped music on hold on SIP/3052-1ef2 Feb 3 14:41:12 DEBUG[29469]: Scheduling timer at 0 sample intervals Feb 3 14:41:12 VERBOSE[29469]: -- agent_call, call to agent '8031' call on 'SIP/3052-1ef2' Feb 3 14:41:12 DEBUG[29469]: Playing beep, lang 'en' Feb 3 14:41:12 DEBUG[29469]: Scheduling timer at 160 sample intervals Feb 3 14:41:12 VERBOSE[29469]: -- Playing 'beep' (language 'en') Feb 3 14:41:12 DEBUG[29469]: Played beep, result '0' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29468]: Not posting to queue since already masked on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 DEBUG[29469]: Scheduling timer at 0 sample intervals Feb 3 14:41:13 DEBUG[29469]: Scheduling timer at 0 sample intervals Feb 3 14:41:13 DEBUG[29469]: Waited for stream, result '0' Feb 3 14:41:13 DEBUG[29469]: Set read format, result '0' Feb 3 14:41:13 DEBUG[29469]: Set write format, result '0' Feb 3 14:41:13 VERBOSE[29469]: -- Called 8031 Feb 3 14:41:13 DEBUG[29469]: Actually Masquerading Zap/1-1(6) into the structure of Local/033797922@agente_out-63aa,1(6) Feb 3 14:41:13 DEBUG[29469]: Got clone lock on 'Zap/1-1' at 0x8162d38 Feb 3 14:41:13 DEBUG[29468]: Didn't get a frame from channel: Local/033797922@agente_out-63aa,2 Feb 3 14:41:13 DEBUG[29469]: Putting channel Zap/1-1 in 64/8 formats Feb 3 14:41:13 DEBUG[29469]: New owner for channel 1 is Zap/1-1 Feb 3 14:41:13 DEBUG[29469]: Updated conferencing on 1, with 0 conference users Feb 3 14:41:13 DEBUG[29469]: Updated conferencing on 1, with 0 conference users Feb 3 14:41:13 DEBUG[29469]: Released clone lock on 'Local/033797922@agente_out-63aa,1' Feb 3 14:41:13 DEBUG[29469]: Done Masquerading Zap/1-1 (6) Feb 3 14:41:13 VERBOSE[29469]: -- Agent/8031 answered Zap/1-1 Feb 3 14:41:13 DEBUG[29468]: Bridge stops bridging channels Local/033797922@agente_out-63aa,2 and Local/033797922@agente_out-63aa,1 Feb 3 14:41:13 DEBUG[29468]: Exiting with DIALSTATUS=ANSWER. Feb 3 14:41:13 VERBOSE[29468]: == Spawn extension (disca, 033797922, 1) exited non-zero on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:13 VERBOSE[29468]: -- Executing Hangup("Local/033797922@agente_out-63aa,2", "") in new stack Feb 3 14:41:13 VERBOSE[29468]: == Spawn extension (disca, h, 1) exited non-zero on 'Local/033797922@agente_out-63aa,2' Feb 3 14:41:17 VERBOSE[29417]: -- Saved useragent "SOYO,Inc." for peer 3050 Feb 3 14:41:17 DEBUG[29435]: Difference is 1992, ms is 269 Feb 3 14:41:17 DEBUG[29465]: Manager received command 'Hangup' Feb 3 14:41:17 DEBUG[29469]: Didn't get a frame from channel: Agent/8031 Feb 3 14:41:17 DEBUG[29469]: Bridge stops bridging channels Zap/1-1 and Agent/8031 Feb 3 14:41:17 DEBUG[29469]: Hangup called for state Up Feb 3 14:41:17 VERBOSE[29469]: -- Started music on hold, class 'silencio', on SIP/3052-1ef2 Feb 3 14:41:17 DEBUG[29469]: Scheduling timer at 160 sample intervals Feb 3 14:41:17 DEBUG[29469]: Exiting with DIALSTATUS=ANSWER. Feb 3 14:41:17 VERBOSE[29469]: == Spawn extension (agente_out, 8031, 1) exited non-zero on 'Zap/1-1' Feb 3 14:41:17 DEBUG[29469]: Hangup: channel: 1 index = 0, normal = 31, callwait = -1, thirdcall = -1 Feb 3 14:41:17 DEBUG[29469]: disabled echo cancellation on channel 1 Feb 3 14:41:17 DEBUG[29469]: Set option TDD MODE, value: OFF(0) on Zap/1-1 Feb 3 14:41:17 DEBUG[29469]: Updated conferencing on 1, with 0 conference users Feb 3 14:41:17 VERBOSE[29469]: -- Hungup 'Zap/1-1' Feb 3 14:41:17 DEBUG[29466]: Generator got voice, switching to phase locked mode Feb 3 14:41:17 DEBUG[29466]: Scheduling timer at 0 sample intervals Feb 3 14:41:18 DEBUG[29466]: Wrapup time expired! Feb 3 14:41:18 DEBUG[29466]: Checking availability of '8031' Feb 3 14:41:19 DEBUG[29417]: Stopping retransmission on '1ea82fa735e74e8158ac6ab1506df11f@200.196.44.5' of Request 102: Found Feb 3 14:41:20 DEBUG[29417]: Setting NAT on RTP to 4 Feb 3 14:41:21 DEBUG[29417]: Stopping retransmission on '1650d8f8040fe54f5a03663118407819@200.196.44.5' of Request 102: Found Feb 3 14:41:24 DEBUG[29434]: Manager received command 'Hangup' Feb 3 14:41:32 DEBUG[29417]: Auto destroying call '1SmFxNsksqTdftlH@172.16.10.124' Feb 3 14:41:34 DEBUG[29434]: Manager received command 'originate' Feb 3 14:41:34 VERBOSE[29471]: -- Executing Dial("Local/8031@agente_out-a509,2", "Agent/8031") in new stack Feb 3 14:41:34 VERBOSE[29471]: -- Stopped music on hold on SIP/3052-1ef2 Feb 3 14:41:34 DEBUG[29471]: Scheduling timer at 0 sample intervals Feb 3 14:41:34 VERBOSE[29471]: -- agent_call, call to agent '8031' call on 'SIP/3052-1ef2' Feb 3 14:41:34 DEBUG[29471]: Playing beep, lang 'en' Feb 3 14:41:34 DEBUG[29471]: Scheduling timer at 160 sample intervals Feb 3 14:41:34 VERBOSE[29471]: -- Playing 'beep' (language 'en') Feb 3 14:41:34 DEBUG[29471]: Played beep, result '0' Feb 3 14:41:35 DEBUG[29471]: Scheduling timer at 0 sample intervals Feb 3 14:41:35 DEBUG[29471]: Scheduling timer at 0 sample intervals Feb 3 14:41:35 DEBUG[29471]: Waited for stream, result '0' Feb 3 14:41:35 DEBUG[29471]: Set read format, result '0' Feb 3 14:41:35 DEBUG[29471]: Set write format, result '0' Feb 3 14:41:35 VERBOSE[29471]: -- Called 8031 Feb 3 14:41:35 DEBUG[29435]: Difference is 920, ms is 135 Feb 3 14:41:35 VERBOSE[29471]: -- Agent/8031 answered Local/8031@agente_out-a509,2 Feb 3 14:41:35 VERBOSE[29470]: > Channel Local/8031@agente_out-a509,1 was answered. Feb 3 14:41:35 VERBOSE[29472]: -- Executing Dial("Local/8031@agente_out-a509,1", "Agent/8033") in new stack Feb 3 14:41:35 VERBOSE[29472]: -- Stopped music on hold on SIP/3050-d2e1 Feb 3 14:41:35 DEBUG[29472]: Scheduling timer at 0 sample intervals Feb 3 14:41:35 VERBOSE[29472]: -- agent_call, call to agent '8033' call on 'SIP/3050-d2e1' Feb 3 14:41:35 DEBUG[29472]: Playing beep, lang 'en' Feb 3 14:41:35 DEBUG[29472]: Scheduling timer at 160 sample intervals Feb 3 14:41:35 VERBOSE[29472]: -- Playing 'beep' (language 'en') Feb 3 14:41:35 DEBUG[29472]: Played beep, result '0' Feb 3 14:41:35 DEBUG[29472]: Scheduling timer at 0 sample intervals Feb 3 14:41:35 DEBUG[29472]: Scheduling timer at 0 sample intervals Feb 3 14:41:35 DEBUG[29472]: Waited for stream, result '0' Feb 3 14:41:35 DEBUG[29472]: Set read format, result '0' Feb 3 14:41:35 DEBUG[29472]: Set write format, result '0' Feb 3 14:41:35 VERBOSE[29472]: -- Called 8033 Feb 3 14:41:35 VERBOSE[29472]: -- Agent/8033 answered Local/8031@agente_out-a509,1 Feb 3 14:41:35 DEBUG[29472]: Planning to masquerade Agent/8033 into the structure of Local/8031@agente_out-a509,2 Feb 3 14:41:35 DEBUG[29472]: Done planning to masquerade Local/8031@agente_out-a509,2 into the structure of Agent/8033 Feb 3 14:41:35 DEBUG[29472]: Not posting to queue since already masked on 'Local/8031@agente_out-a509,1' Feb 3 14:41:35 DEBUG[29471]: Actually Masquerading Agent/8033(6) into the structure of Local/8031@agente_out-a509,2(6) Feb 3 14:41:35 DEBUG[29471]: Got clone lock on 'Agent/8033' at 0x8174a40 Feb 3 14:41:35 DEBUG[29472]: Didn't get a frame from channel: Local/8031@agente_out-a509,1 Feb 3 14:41:35 DEBUG[29471]: Putting channel Agent/8033 in 64/8 formats Feb 3 14:41:35 DEBUG[29471]: Released clone lock on 'Local/8031@agente_out-a509,2' Feb 3 14:41:35 DEBUG[29471]: Done Masquerading Agent/8033 (6) Feb 3 14:41:35 DEBUG[29472]: Bridge stops bridging channels Local/8031@agente_out-a509,1 and Local/8031@agente_out-a509,2 Feb 3 14:41:35 DEBUG[29472]: Exiting with DIALSTATUS=ANSWER. Feb 3 14:41:35 VERBOSE[29472]: == Spawn extension (agente_out, 8033, 1) exited non-zero on 'Local/8031@agente_out-a509,1' Feb 3 14:41:40 DEBUG[29434]: Manager received command 'Hangup' Feb 3 14:41:40 DEBUG[29471]: Didn't get a frame from channel: Agent/8033 Feb 3 14:41:40 DEBUG[29471]: Bridge stops bridging channels Agent/8033 and Agent/8031 Feb 3 14:41:40 DEBUG[29471]: Hangup called for state Up Feb 3 14:41:40 VERBOSE[29471]: -- Started music on hold, class 'silencio', on SIP/3052-1ef2 Feb 3 14:41:40 DEBUG[29471]: Scheduling timer at 160 sample intervals Feb 3 14:41:40 DEBUG[29471]: Exiting with DIALSTATUS=ANSWER. Feb 3 14:41:40 VERBOSE[29471]: == Spawn extension (agente_out, 8031, 1) exited non-zero on 'Agent/8033' Feb 3 14:41:40 DEBUG[29471]: Hangup called for state Up Feb 3 14:41:40 VERBOSE[29471]: -- Started music on hold, class 'silencio', on SIP/3050-d2e1 Feb 3 14:41:40 DEBUG[29471]: Scheduling timer at 160 sample intervals Feb 3 14:41:40 DEBUG[29466]: Generator got voice, switching to phase locked mode Feb 3 14:41:40 DEBUG[29466]: Scheduling timer at 0 sample intervals Feb 3 14:41:41 DEBUG[29466]: Wrapup time expired! Feb 3 14:41:41 DEBUG[29466]: Checking availability of '8031' Feb 3 14:41:54 DEBUG[29417]: Auto destroying call 'DE7CF6354CF1494F9E6C07F5D610EDF2@gateway.planetarium.com.br' Feb 3 14:42:19 DEBUG[29417]: Stopping retransmission on '74708b1d7e7bc8727d75eccf65bbf88f@200.196.44.5' of Request 102: Found Feb 3 14:42:20 VERBOSE[29481]: -- Starting simple switch on 'Zap/1-1' Feb 3 14:42:21 NOTICE[29481]: Got event 2 (Ring/Answered)... Feb 3 14:42:25 NOTICE[29481]: Got event 2 (Ring/Answered)... Feb 3 14:42:25 VERBOSE[29481]: -- Executing Macro("Zap/1-1", "tronco_faketone_default|1") in new stack Feb 3 14:42:25 VERBOSE[29481]: -- Executing SetVar("Zap/1-1", "TRONCO=1") in new stack Feb 3 14:42:25 VERBOSE[29481]: -- Executing Goto("Zap/1-1", "tronco_faketone_default|s|1") in new stack Feb 3 14:42:25 VERBOSE[29481]: -- Goto (tronco_faketone_default,s,1) Feb 3 14:42:25 VERBOSE[29481]: == Channel 'Zap/1-1' jumping out of macro 'tronco_faketone_default' Feb 3 14:42:25 VERBOSE[29481]: -- Executing DigitTimeout("Zap/1-1", "5") in new stack Feb 3 14:42:25 VERBOSE[29481]: -- Set Digit Timeout to 5 Feb 3 14:42:25 VERBOSE[29481]: -- Executing ResponseTimeout("Zap/1-1", "5") in new stack Feb 3 14:42:25 VERBOSE[29481]: -- Set Response Timeout to 5 Feb 3 14:42:25 VERBOSE[29481]: -- Executing Answer("Zap/1-1", "") in new stack Feb 3 14:42:25 DEBUG[29481]: Took Zap/1-1 off hook Feb 3 14:42:25 DEBUG[29481]: Enabled echo cancellation on channel 1 Feb 3 14:42:25 DEBUG[29481]: No echo training requested Feb 3 14:42:25 VERBOSE[29481]: -- Executing PlayTones("Zap/1-1", "dial") in new stack Feb 3 14:42:25 DEBUG[29481]: Scheduling timer at 160 sample intervals Feb 3 14:42:25 DEBUG[29481]: Generator got voice, switching to phase locked mode Feb 3 14:42:25 DEBUG[29481]: Scheduling timer at 0 sample intervals Feb 3 14:42:26 DEBUG[29481]: DTMF digit: 3 on Zap/1-1 Feb 3 14:42:26 VERBOSE[29481]: -- Invalid extension '3' in context 'tronco_faketone_default' on Zap/1-1 Feb 3 14:42:26 VERBOSE[29481]: == CDR updated on Zap/1-1 Feb 3 14:42:26 VERBOSE[29481]: -- Executing StopPlayTones("Zap/1-1", "") in new stack Feb 3 14:42:26 DEBUG[29481]: Scheduling timer at 0 sample intervals Feb 3 14:42:26 VERBOSE[29481]: -- Executing SetVar("Zap/1-1", "PRIMEIRODIGITO=3") in new stack Feb 3 14:42:26 VERBOSE[29481]: -- Executing Goto("Zap/1-1", "tronco_faketone_aux|s|1") in new stack Feb 3 14:42:26 VERBOSE[29481]: -- Goto (tronco_faketone_aux,s,1) Feb 3 14:42:26 VERBOSE[29481]: -- Executing NoOp("Zap/1-1", "") in new stack Feb 3 14:42:27 DEBUG[29481]: DTMF digit: 0 on Zap/1-1 Feb 3 14:42:27 DEBUG[29481]: DTMF digit: 9 on Zap/1-1 Feb 3 14:42:27 DEBUG[29481]: DTMF digit: 9 on Zap/1-1 Feb 3 14:42:32 VERBOSE[29481]: == CDR updated on Zap/1-1 Feb 3 14:42:32 VERBOSE[29481]: -- Executing Goto("Zap/1-1", "FXOCH1_out|3099|1") in new stack Feb 3 14:42:32 VERBOSE[29481]: -- Goto (FXOCH1_out,3099,1) Feb 3 14:42:32 DEBUG[29481]: Expression is '1' Feb 3 14:42:32 VERBOSE[29481]: -- Executing GotoIf("Zap/1-1", "1 ? 2:4") in new stack Feb 3 14:42:32 VERBOSE[29481]: -- Goto (FXOCH1_out,3099,2) Feb 3 14:42:32 VERBOSE[29481]: -- Executing SetVar("Zap/1-1", "CHAMADAINTERNA=T") in new stack Feb 3 14:42:32 VERBOSE[29481]: -- Executing SetCIDNum("Zap/1-1", "7922") in new stack Feb 3 14:42:32 VERBOSE[29481]: -- Executing Goto("Zap/1-1", "disca|3099|1") in new stack Feb 3 14:42:32 VERBOSE[29481]: -- Goto (disca,3099,1) Feb 3 14:42:32 VERBOSE[29481]: -- Executing Goto("Zap/1-1", "principal_in|3099|1") in new stack Feb 3 14:42:32 VERBOSE[29481]: -- Goto (principal_in,3099,1) Feb 3 14:42:32 VERBOSE[29481]: -- Executing Goto("Zap/1-1", "fila_suporte|3099|1") in new stack Feb 3 14:42:32 VERBOSE[29481]: -- Goto (fila_suporte,3099,1) Feb 3 14:42:32 VERBOSE[29481]: -- Executing SetLanguage("Zap/1-1", "br") in new stack Feb 3 14:42:32 VERBOSE[29481]: -- Executing Answer("Zap/1-1", "") in new stack Feb 3 14:42:32 VERBOSE[29481]: -- Executing Wait("Zap/1-1", "3") in new stack Feb 3 14:42:35 VERBOSE[29481]: -- Executing SetCIDName("Zap/1-1", "Fila suporte - PABX Spress") in new stack Feb 3 14:42:35 VERBOSE[29481]: -- Executing Queue("Zap/1-1", "suporte|tn|||") in new stack Feb 3 14:42:35 DEBUG[29481]: queue: suporte, options: tn, url: , announce: , timeout: 0, priority: 0 Feb 3 14:42:35 VERBOSE[29481]: -- Started music on hold, class 'default', on Zap/1-1 Feb 3 14:42:35 DEBUG[29481]: Scheduling timer at 160 sample intervals Feb 3 14:42:35 VERBOSE[29481]: -- Stopped music on hold on Zap/1-1 Feb 3 14:42:35 DEBUG[29481]: Scheduling timer at 0 sample intervals Feb 3 14:42:35 DEBUG[29481]: Scheduling timer at 160 sample intervals Feb 3 14:42:35 VERBOSE[29481]: -- Playing 'queue-youarenext' (language 'br') Feb 3 14:42:35 DEBUG[29422]: Manager received command 'queuestatus' Feb 3 14:42:35 DEBUG[29422]: Manager received command 'status' Feb 3 14:42:36 DEBUG[29434]: Manager received command 'queuestatus' Feb 3 14:42:36 DEBUG[29465]: Manager received command 'queuestatus' Feb 3 14:42:43 DEBUG[29481]: Scheduling timer at 0 sample intervals Feb 3 14:42:43 DEBUG[29481]: Scheduling timer at 0 sample intervals Feb 3 14:42:43 VERBOSE[29481]: -- Told Zap/1-1 in suporte their queue position (which was 1) Feb 3 14:42:43 DEBUG[29481]: Scheduling timer at 160 sample intervals Feb 3 14:42:43 VERBOSE[29481]: -- Playing 'queue-thankyou' (language 'br') Feb 3 14:42:45 DEBUG[29481]: Scheduling timer at 0 sample intervals Feb 3 14:42:45 DEBUG[29481]: Scheduling timer at 0 sample intervals Feb 3 14:42:45 VERBOSE[29481]: -- Started music on hold, class 'default', on Zap/1-1 Feb 3 14:42:45 DEBUG[29481]: Scheduling timer at 160 sample intervals Feb 3 14:42:45 VERBOSE[29481]: -- Stopped music on hold on SIP/3052-1ef2 Feb 3 14:42:45 DEBUG[29481]: Scheduling timer at 0 sample intervals Feb 3 14:42:45 VERBOSE[29481]: -- agent_call, call to agent '8031' call on 'SIP/3052-1ef2' Feb 3 14:42:45 DEBUG[29481]: Playing beep, lang 'en' Feb 3 14:42:45 DEBUG[29481]: Scheduling timer at 160 sample intervals Feb 3 14:42:45 VERBOSE[29481]: -- Playing 'beep' (language 'en') Feb 3 14:42:45 DEBUG[29481]: Played beep, result '0' Feb 3 14:42:46 DEBUG[29481]: Scheduling timer at 0 sample intervals Feb 3 14:42:46 DEBUG[29481]: Scheduling timer at 0 sample intervals Feb 3 14:42:46 DEBUG[29481]: Waited for stream, result '0' Feb 3 14:42:46 DEBUG[29481]: Set read format, result '0' Feb 3 14:42:46 DEBUG[29481]: Set write format, result '0' Feb 3 14:42:46 VERBOSE[29481]: -- Called agent/8031 Feb 3 14:42:46 VERBOSE[29481]: -- Agent/8031 answered Zap/1-1 Feb 3 14:42:46 DEBUG[29481]: Set option TONE VERIFY, mode: MUTECONF/MAX(2) on Zap/1-1 Feb 3 14:42:46 VERBOSE[29481]: -- Stopped music on hold on Zap/1-1 Feb 3 14:42:46 DEBUG[29481]: Scheduling timer at 0 sample intervals Feb 3 14:42:46 DEBUG[29434]: Manager received command 'queuestatus' Feb 3 14:42:46 DEBUG[29465]: Manager received command 'queuestatus' Feb 3 14:43:03 DEBUG[29465]: Manager received command 'Redirect' Feb 3 14:43:03 DEBUG[29481]: Didn't get a frame from channel: Zap/1-1 Feb 3 14:43:03 DEBUG[29481]: Bridge stops bridging channels Zap/1-1 and Agent/8031 Feb 3 14:43:03 DEBUG[29481]: Hangup called for state Up Feb 3 14:43:03 VERBOSE[29481]: -- Started music on hold, class 'silencio', on SIP/3052-1ef2 Feb 3 14:43:03 DEBUG[29481]: Scheduling timer at 160 sample intervals Feb 3 14:43:03 VERBOSE[29481]: == Spawn extension (agente_out, 8033, 0) exited non-zero on 'Zap/1-1' Feb 3 14:43:03 VERBOSE[29481]: -- Executing Dial("Zap/1-1", "Agent/8033") in new stack DEADLOCK HERE Feb 3 14:43:03 DEBUG[29466]: Generator got voice, switching to phase locked mode Feb 3 14:43:03 DEBUG[29466]: Scheduling timer at 0 sample intervals Feb 3 14:43:15 DEBUG[29417]: Auto destroying call 'DE7CF6354CF1494F9E6C07F5D610EDF2@gateway.planetarium.com.br' Feb 3 14:43:19 DEBUG[29417]: Stopping retransmission on '22ba41d8360c253a26f25afa22ba7f01@200.196.44.5' of Request 102: Found Feb 3 14:43:33 DEBUG[29484]: Manager received command 'login' Feb 3 14:43:33 VERBOSE[29484]: == Parsing '/etc/asterisk/manager.conf': Feb 3 14:43:33 VERBOSE[29484]: == Parsing '/etc/asterisk/manager.conf': Found Feb 3 14:43:33 DEBUG[29484]: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer Feb 3 14:43:33 DEBUG[29484]: 200.196.44.23/255.255.255.255/255.255.255.255 appended to acl for peer Feb 3 14:43:33 DEBUG[29484]: ##### Testing 200.196.44.23 with 0.0.0.0 Feb 3 14:43:33 DEBUG[29484]: ##### Testing 200.196.44.23 with 200.196.44.23 Feb 3 14:43:33 VERBOSE[29484]: == Manager 'monitornagios' logged on from 200.196.44.23 Feb 3 14:43:33 DEBUG[29484]: Manager received command 'ZapShowChannels' Feb 3 14:43:33 DEBUG[29484]: Manager received command 'logoff' Feb 3 14:43:33 VERBOSE[29484]: == Manager 'monitornagios' logged off from 200.196.44.23