Delay in calls
Posted: Sun Jun 22, 2014 3:18 am
please check these logs
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- AMD: Word detected. iWordsCount:4
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- AMD: ANSWERING MACHINE: iWordsCount:4
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- Executing [8369@default:4] AGI("SIP/rapidvox-00000030", "VD_amd.agi|8369") in new stack
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- Launched AGI Script /var/lib/asterisk/agi-bin/VD_amd.agi
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[Jun 22 04:17:20] DEBUG[22636] res_agi.c: SIP/rapidvox-00000030 hungup
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] == Spawn extension (default, 8369, 4) exited non-zero on 'SIP/rapidvox-00000030'
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- Executing [h@default:1] DeadAGI("SIP/rapidvox-00000030", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
[Jun 22 04:17:22] VERBOSE[22663] logger.c: [Jun 22 04:17:22] == Parsing '/etc/asterisk/manager.conf': [Jun 22 04:17:22] VERBOSE[22663] logger.c: [Jun 22 04:17:22] Found
[Jun 22 04:17:22] VERBOSE[22663] logger.c: [Jun 22 04:17:22] == Manager 'sendcron' logged on from 127.0.0.1
[Jun 22 04:17:22] VERBOSE[22664] logger.c: [Jun 22 04:17:22] -- Executing [14165301299@default:1] Set("Local/14165301299@default-ba79,2", "CALLERID(number)= 5877930611") in new stack
[Jun 22 04:17:22] VERBOSE[22664] logger.c: [Jun 22 04:17:22] -- Executing [14165301299@default:2] Dial("Local/14165301299@default-ba79,2", "SIP/rapidvox/14165301299") in new stack
[Jun 22 04:17:22] VERBOSE[22664] logger.c: [Jun 22 04:17:22] -- Called rapidvox/14165301299
[Jun 22 04:17:25] VERBOSE[22664] logger.c: [Jun 22 04:17:25] -- SIP/rapidvox-00000031 is ringing
[Jun 22 04:17:25] VERBOSE[22664] logger.c: [Jun 22 04:17:25] -- SIP/rapidvox-00000031 is making progress passing it to Local/14165301299@default-ba79,2
[Jun 22 04:17:27] VERBOSE[22130] logger.c: [Jun 22 04:17:27] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:17:27] VERBOSE[22131] logger.c: [Jun 22 04:17:27] == Spawn extension (default, 14169253044, 2) exited non-zero on 'Local/14169253044@default-e2fa,2'
[Jun 22 04:17:27] VERBOSE[22131] logger.c: [Jun 22 04:17:27] -- Executing [h@default:1] DeadAGI("Local/14169253044@default-e2fa,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL----------") in new stack
[Jun 22 04:17:28] VERBOSE[22131] logger.c: [Jun 22 04:17:28] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
[Jun 22 04:17:50] VERBOSE[22664] logger.c: [Jun 22 04:17:50] -- SIP/rapidvox-00000031 answered Local/14165301299@default-ba79,2
[Jun 22 04:17:50] VERBOSE[22663] logger.c: [Jun 22 04:17:50] > Channel Local/14165301299@default-ba79,1 was answered.
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- Executing [8369@default:1] Playback("Local/14165301299@default-ba79,1", "sip-silence") in new stack
[Jun 22 04:17:50] VERBOSE[22663] logger.c: [Jun 22 04:17:50] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- Playing 'sip-silence' (language 'en')
[Jun 22 04:17:50] WARNING[22779] file.c: Unexpected control subclass '-1'
[Jun 22 04:17:50] VERBOSE[22664] logger.c: [Jun 22 04:17:50] -- Executing [h@default:1] DeadAGI("Local/14165301299@default-ba79,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----28-----0") in new stack
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- Executing [8369@default:2] AGI("SIP/rapidvox-00000031", "agi://127.0.0.1:4577/call_log") in new stack
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- Executing [8369@default:3] AMD("SIP/rapidvox-00000031", "2000|2000|1000|5000|120|50|4|256") in new stack
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- AMD: SIP/rapidvox-00000031 (null) (null) (Fmt: 64)
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- AMD: initialSilence [2000] greeting [2000] afterGreetingSilence [1000] totalAnalysisTime [5000] minimumWordLength [120] betweenWordsSilence [50] maximumNumberOfWords [4] silenceThreshold [256]
[Jun 22 04:17:51] VERBOSE[22779] logger.c: [Jun 22 04:17:51] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:17:51] VERBOSE[22779] logger.c: [Jun 22 04:17:51] -- AMD: Word detected. iWordsCount:1
[Jun 22 04:17:51] VERBOSE[22664] logger.c: [Jun 22 04:17:51] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... --28-----0 completed, returning 0
[Jun 22 04:17:51] VERBOSE[22664] logger.c: [Jun 22 04:17:51] == Spawn extension (default, 14165301299, 2) exited non-zero on 'Local/14165301299@default-ba79,2'
[Jun 22 04:17:52] VERBOSE[22779] logger.c: [Jun 22 04:17:52] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:17:52] VERBOSE[22779] logger.c: [Jun 22 04:17:52] -- AMD: Word detected. iWordsCount:2
[Jun 22 04:17:52] VERBOSE[22779] logger.c: [Jun 22 04:17:52] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:17:52] VERBOSE[22779] logger.c: [Jun 22 04:17:52] -- AMD: Word detected. iWordsCount:3
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- AMD: Word detected. iWordsCount:4
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- AMD: ANSWERING MACHINE: iWordsCount:4
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- Executing [8369@default:4] AGI("SIP/rapidvox-00000031", "VD_amd.agi|8369") in new stack
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- Launched AGI Script /var/lib/asterisk/agi-bin/VD_amd.agi
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[Jun 22 04:17:53] DEBUG[22779] res_agi.c: SIP/rapidvox-00000031 hungup
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] == Spawn extension (default, 8369, 4) exited non-zero on 'SIP/rapidvox-00000031'
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- Executing [h@default:1] DeadAGI("SIP/rapidvox-00000031", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
[Jun 22 04:17:55] VERBOSE[22806] logger.c: [Jun 22 04:17:55] == Parsing '/etc/asterisk/manager.conf': [Jun 22 04:17:55] VERBOSE[22806] logger.c: [Jun 22 04:17:55] Found
[Jun 22 04:17:55] VERBOSE[22806] logger.c: [Jun 22 04:17:55] == Manager 'sendcron' logged on from 127.0.0.1
[Jun 22 04:17:55] VERBOSE[22807] logger.c: [Jun 22 04:17:55] -- Executing [14167593592@default:1] Set("Local/14167593592@default-9868,2", "CALLERID(number)= 5877930611") in new stack
[Jun 22 04:17:55] VERBOSE[22807] logger.c: [Jun 22 04:17:55] -- Executing [14167593592@default:2] Dial("Local/14167593592@default-9868,2", "SIP/rapidvox/14167593592") in new stack
[Jun 22 04:17:55] VERBOSE[22807] logger.c: [Jun 22 04:17:55] -- Called rapidvox/14167593592
[Jun 22 04:17:57] VERBOSE[22807] logger.c: [Jun 22 04:17:57] -- SIP/rapidvox-00000032 is making progress passing it to Local/14167593592@default-9868,2
[Jun 22 04:18:02] VERBOSE[22859] logger.c: [Jun 22 04:18:02] == Parsing '/etc/asterisk/manager.conf': [Jun 22 04:18:02] VERBOSE[22859] logger.c: [Jun 22 04:18:02] Found
[Jun 22 04:18:02] VERBOSE[22859] logger.c: [Jun 22 04:18:02] == Manager 'sendcron' logged on from 127.0.0.1
[Jun 22 04:18:02] VERBOSE[22859] logger.c: [Jun 22 04:18:02] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:18:02] VERBOSE[22866] logger.c: [Jun 22 04:18:02] == Parsing '/etc/asterisk/manager.conf': [Jun 22 04:18:02] VERBOSE[22866] logger.c: [Jun 22 04:18:02] Found
[Jun 22 04:18:02] VERBOSE[22866] logger.c: [Jun 22 04:18:02] == Manager 'sendcron' logged on from 127.0.0.1
[Jun 22 04:18:04] VERBOSE[22866] logger.c: [Jun 22 04:18:04] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:18:07] VERBOSE[23214] logger.c: [Jun 22 04:18:07] == Parsing '/etc/asterisk/manager.conf': [Jun 22 04:18:07] VERBOSE[23214] logger.c: [Jun 22 04:18:07] Found
[Jun 22 04:18:07] VERBOSE[23214] logger.c: [Jun 22 04:18:07] == Manager 'sendcron' logged on from 127.0.0.1
[Jun 22 04:18:07] VERBOSE[23214] logger.c: [Jun 22 04:18:07] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:18:09] VERBOSE[22807] logger.c: [Jun 22 04:18:09] -- SIP/rapidvox-00000032 answered Local/14167593592@default-9868,2
[Jun 22 04:18:09] VERBOSE[22806] logger.c: [Jun 22 04:18:09] > Channel Local/14167593592@default-9868,1 was answered.
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- Executing [8369@default:1] Playback("Local/14167593592@default-9868,1", "sip-silence") in new stack
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- Playing 'sip-silence' (language 'en')
[Jun 22 04:18:09] WARNING[23281] file.c: Unexpected control subclass '-1'
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- Executing [8369@default:2] AGI("Local/14167593592@default-9868,1", "agi://127.0.0.1:4577/call_log") in new stack
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- Executing [8369@default:3] AMD("Local/14167593592@default-9868,1", "2000|2000|1000|5000|120|50|4|256") in new stack
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- AMD: Local/14167593592@default-9868,1 (null) (null) (Fmt: 64)
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- AMD: initialSilence [2000] greeting [2000] afterGreetingSilence [1000] totalAnalysisTime [5000] minimumWordLength [120] betweenWordsSilence [50] maximumNumberOfWords [4] silenceThreshold [256]
[Jun 22 04:18:10] VERBOSE[23281] logger.c: [Jun 22 04:18:10] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:18:10] VERBOSE[22807] logger.c: [Jun 22 04:18:10] -- Executing [h@default:1] DeadAGI("Local/14167593592@default-9868,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----15-----1") in new stack
[Jun 22 04:18:11] VERBOSE[23281] logger.c: [Jun 22 04:18:11] -- AMD: Word detected. iWordsCount:1
[Jun 22 04:18:11] VERBOSE[23281] logger.c: [Jun 22 04:18:11] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:18:11] VERBOSE[22807] logger.c: [Jun 22 04:18:11] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... --15-----1 completed, returning 0
[Jun 22 04:18:11] VERBOSE[22807] logger.c: [Jun 22 04:18:11] == Spawn extension (default, 14167593592, 2) exited non-zero on 'Local/14167593592@default-9868,2'
[Jun 22 04:18:11] VERBOSE[22806] logger.c: [Jun 22 04:18:11] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- AMD: HUMAN: silenceDuration:1000 afterGreetingSilence:1000
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Executing [8369@default:4] AGI("SIP/rapidvox-00000032", "VD_amd.agi|8369") in new stack
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Launched AGI Script /var/lib/asterisk/agi-bin/VD_amd.agi
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- AGI Script VD_amd.agi completed, returning 0
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Executing [8369@default:5] AGI("SIP/rapidvox-00000032", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Jun 22 04:18:12] ERROR[23281] utils.c: write() returned error: Broken pipe
[Jun 22 04:18:12] ERROR[23281] utils.c: write() returned error: Broken pipe
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Executing [192*168*000*099*8600051@default:1] Goto("SIP/rapidvox-00000032", "default|8600051|1") in new stack
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Goto (default,8600051,1)
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Executing [8600051@default:1] MeetMe("SIP/rapidvox-00000032", "8600051|F") in new stack
[Jun 22 04:18:15] VERBOSE[23281] logger.c: [Jun 22 04:18:15] == Spawn extension (default, 8600051, 1) exited non-zero on 'SIP/rapidvox-00000032'
[Jun 22 04:18:15] VERBOSE[23281] logger.c: [Jun 22 04:18:15] -- Executing [h@default:1] DeadAGI("SIP/rapidvox-00000032", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Jun 22 04:18:15] VERBOSE[23281] logger.c: [Jun 22 04:18:15] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- AMD: Word detected. iWordsCount:4
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- AMD: ANSWERING MACHINE: iWordsCount:4
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- Executing [8369@default:4] AGI("SIP/rapidvox-00000030", "VD_amd.agi|8369") in new stack
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- Launched AGI Script /var/lib/asterisk/agi-bin/VD_amd.agi
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[Jun 22 04:17:20] DEBUG[22636] res_agi.c: SIP/rapidvox-00000030 hungup
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] == Spawn extension (default, 8369, 4) exited non-zero on 'SIP/rapidvox-00000030'
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- Executing [h@default:1] DeadAGI("SIP/rapidvox-00000030", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Jun 22 04:17:20] VERBOSE[22636] logger.c: [Jun 22 04:17:20] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
[Jun 22 04:17:22] VERBOSE[22663] logger.c: [Jun 22 04:17:22] == Parsing '/etc/asterisk/manager.conf': [Jun 22 04:17:22] VERBOSE[22663] logger.c: [Jun 22 04:17:22] Found
[Jun 22 04:17:22] VERBOSE[22663] logger.c: [Jun 22 04:17:22] == Manager 'sendcron' logged on from 127.0.0.1
[Jun 22 04:17:22] VERBOSE[22664] logger.c: [Jun 22 04:17:22] -- Executing [14165301299@default:1] Set("Local/14165301299@default-ba79,2", "CALLERID(number)= 5877930611") in new stack
[Jun 22 04:17:22] VERBOSE[22664] logger.c: [Jun 22 04:17:22] -- Executing [14165301299@default:2] Dial("Local/14165301299@default-ba79,2", "SIP/rapidvox/14165301299") in new stack
[Jun 22 04:17:22] VERBOSE[22664] logger.c: [Jun 22 04:17:22] -- Called rapidvox/14165301299
[Jun 22 04:17:25] VERBOSE[22664] logger.c: [Jun 22 04:17:25] -- SIP/rapidvox-00000031 is ringing
[Jun 22 04:17:25] VERBOSE[22664] logger.c: [Jun 22 04:17:25] -- SIP/rapidvox-00000031 is making progress passing it to Local/14165301299@default-ba79,2
[Jun 22 04:17:27] VERBOSE[22130] logger.c: [Jun 22 04:17:27] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:17:27] VERBOSE[22131] logger.c: [Jun 22 04:17:27] == Spawn extension (default, 14169253044, 2) exited non-zero on 'Local/14169253044@default-e2fa,2'
[Jun 22 04:17:27] VERBOSE[22131] logger.c: [Jun 22 04:17:27] -- Executing [h@default:1] DeadAGI("Local/14169253044@default-e2fa,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0-----CANCEL----------") in new stack
[Jun 22 04:17:28] VERBOSE[22131] logger.c: [Jun 22 04:17:28] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
[Jun 22 04:17:50] VERBOSE[22664] logger.c: [Jun 22 04:17:50] -- SIP/rapidvox-00000031 answered Local/14165301299@default-ba79,2
[Jun 22 04:17:50] VERBOSE[22663] logger.c: [Jun 22 04:17:50] > Channel Local/14165301299@default-ba79,1 was answered.
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- Executing [8369@default:1] Playback("Local/14165301299@default-ba79,1", "sip-silence") in new stack
[Jun 22 04:17:50] VERBOSE[22663] logger.c: [Jun 22 04:17:50] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- Playing 'sip-silence' (language 'en')
[Jun 22 04:17:50] WARNING[22779] file.c: Unexpected control subclass '-1'
[Jun 22 04:17:50] VERBOSE[22664] logger.c: [Jun 22 04:17:50] -- Executing [h@default:1] DeadAGI("Local/14165301299@default-ba79,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----28-----0") in new stack
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- Executing [8369@default:2] AGI("SIP/rapidvox-00000031", "agi://127.0.0.1:4577/call_log") in new stack
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- Executing [8369@default:3] AMD("SIP/rapidvox-00000031", "2000|2000|1000|5000|120|50|4|256") in new stack
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- AMD: SIP/rapidvox-00000031 (null) (null) (Fmt: 64)
[Jun 22 04:17:50] VERBOSE[22779] logger.c: [Jun 22 04:17:50] -- AMD: initialSilence [2000] greeting [2000] afterGreetingSilence [1000] totalAnalysisTime [5000] minimumWordLength [120] betweenWordsSilence [50] maximumNumberOfWords [4] silenceThreshold [256]
[Jun 22 04:17:51] VERBOSE[22779] logger.c: [Jun 22 04:17:51] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:17:51] VERBOSE[22779] logger.c: [Jun 22 04:17:51] -- AMD: Word detected. iWordsCount:1
[Jun 22 04:17:51] VERBOSE[22664] logger.c: [Jun 22 04:17:51] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... --28-----0 completed, returning 0
[Jun 22 04:17:51] VERBOSE[22664] logger.c: [Jun 22 04:17:51] == Spawn extension (default, 14165301299, 2) exited non-zero on 'Local/14165301299@default-ba79,2'
[Jun 22 04:17:52] VERBOSE[22779] logger.c: [Jun 22 04:17:52] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:17:52] VERBOSE[22779] logger.c: [Jun 22 04:17:52] -- AMD: Word detected. iWordsCount:2
[Jun 22 04:17:52] VERBOSE[22779] logger.c: [Jun 22 04:17:52] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:17:52] VERBOSE[22779] logger.c: [Jun 22 04:17:52] -- AMD: Word detected. iWordsCount:3
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- AMD: Word detected. iWordsCount:4
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- AMD: ANSWERING MACHINE: iWordsCount:4
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- Executing [8369@default:4] AGI("SIP/rapidvox-00000031", "VD_amd.agi|8369") in new stack
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- Launched AGI Script /var/lib/asterisk/agi-bin/VD_amd.agi
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- Playing 'sip-silence' (escape_digits=) (sample_offset 0)
[Jun 22 04:17:53] DEBUG[22779] res_agi.c: SIP/rapidvox-00000031 hungup
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] == Spawn extension (default, 8369, 4) exited non-zero on 'SIP/rapidvox-00000031'
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- Executing [h@default:1] DeadAGI("SIP/rapidvox-00000031", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Jun 22 04:17:53] VERBOSE[22779] logger.c: [Jun 22 04:17:53] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0
[Jun 22 04:17:55] VERBOSE[22806] logger.c: [Jun 22 04:17:55] == Parsing '/etc/asterisk/manager.conf': [Jun 22 04:17:55] VERBOSE[22806] logger.c: [Jun 22 04:17:55] Found
[Jun 22 04:17:55] VERBOSE[22806] logger.c: [Jun 22 04:17:55] == Manager 'sendcron' logged on from 127.0.0.1
[Jun 22 04:17:55] VERBOSE[22807] logger.c: [Jun 22 04:17:55] -- Executing [14167593592@default:1] Set("Local/14167593592@default-9868,2", "CALLERID(number)= 5877930611") in new stack
[Jun 22 04:17:55] VERBOSE[22807] logger.c: [Jun 22 04:17:55] -- Executing [14167593592@default:2] Dial("Local/14167593592@default-9868,2", "SIP/rapidvox/14167593592") in new stack
[Jun 22 04:17:55] VERBOSE[22807] logger.c: [Jun 22 04:17:55] -- Called rapidvox/14167593592
[Jun 22 04:17:57] VERBOSE[22807] logger.c: [Jun 22 04:17:57] -- SIP/rapidvox-00000032 is making progress passing it to Local/14167593592@default-9868,2
[Jun 22 04:18:02] VERBOSE[22859] logger.c: [Jun 22 04:18:02] == Parsing '/etc/asterisk/manager.conf': [Jun 22 04:18:02] VERBOSE[22859] logger.c: [Jun 22 04:18:02] Found
[Jun 22 04:18:02] VERBOSE[22859] logger.c: [Jun 22 04:18:02] == Manager 'sendcron' logged on from 127.0.0.1
[Jun 22 04:18:02] VERBOSE[22859] logger.c: [Jun 22 04:18:02] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:18:02] VERBOSE[22866] logger.c: [Jun 22 04:18:02] == Parsing '/etc/asterisk/manager.conf': [Jun 22 04:18:02] VERBOSE[22866] logger.c: [Jun 22 04:18:02] Found
[Jun 22 04:18:02] VERBOSE[22866] logger.c: [Jun 22 04:18:02] == Manager 'sendcron' logged on from 127.0.0.1
[Jun 22 04:18:04] VERBOSE[22866] logger.c: [Jun 22 04:18:04] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:18:07] VERBOSE[23214] logger.c: [Jun 22 04:18:07] == Parsing '/etc/asterisk/manager.conf': [Jun 22 04:18:07] VERBOSE[23214] logger.c: [Jun 22 04:18:07] Found
[Jun 22 04:18:07] VERBOSE[23214] logger.c: [Jun 22 04:18:07] == Manager 'sendcron' logged on from 127.0.0.1
[Jun 22 04:18:07] VERBOSE[23214] logger.c: [Jun 22 04:18:07] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:18:09] VERBOSE[22807] logger.c: [Jun 22 04:18:09] -- SIP/rapidvox-00000032 answered Local/14167593592@default-9868,2
[Jun 22 04:18:09] VERBOSE[22806] logger.c: [Jun 22 04:18:09] > Channel Local/14167593592@default-9868,1 was answered.
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- Executing [8369@default:1] Playback("Local/14167593592@default-9868,1", "sip-silence") in new stack
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- Playing 'sip-silence' (language 'en')
[Jun 22 04:18:09] WARNING[23281] file.c: Unexpected control subclass '-1'
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- Executing [8369@default:2] AGI("Local/14167593592@default-9868,1", "agi://127.0.0.1:4577/call_log") in new stack
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- Executing [8369@default:3] AMD("Local/14167593592@default-9868,1", "2000|2000|1000|5000|120|50|4|256") in new stack
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- AMD: Local/14167593592@default-9868,1 (null) (null) (Fmt: 64)
[Jun 22 04:18:09] VERBOSE[23281] logger.c: [Jun 22 04:18:09] -- AMD: initialSilence [2000] greeting [2000] afterGreetingSilence [1000] totalAnalysisTime [5000] minimumWordLength [120] betweenWordsSilence [50] maximumNumberOfWords [4] silenceThreshold [256]
[Jun 22 04:18:10] VERBOSE[23281] logger.c: [Jun 22 04:18:10] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:18:10] VERBOSE[22807] logger.c: [Jun 22 04:18:10] -- Executing [h@default:1] DeadAGI("Local/14167593592@default-9868,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----15-----1") in new stack
[Jun 22 04:18:11] VERBOSE[23281] logger.c: [Jun 22 04:18:11] -- AMD: Word detected. iWordsCount:1
[Jun 22 04:18:11] VERBOSE[23281] logger.c: [Jun 22 04:18:11] -- AMD: Changed state to STATE_IN_SILENCE
[Jun 22 04:18:11] VERBOSE[22807] logger.c: [Jun 22 04:18:11] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... --15-----1 completed, returning 0
[Jun 22 04:18:11] VERBOSE[22807] logger.c: [Jun 22 04:18:11] == Spawn extension (default, 14167593592, 2) exited non-zero on 'Local/14167593592@default-9868,2'
[Jun 22 04:18:11] VERBOSE[22806] logger.c: [Jun 22 04:18:11] == Manager 'sendcron' logged off from 127.0.0.1
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- AMD: HUMAN: silenceDuration:1000 afterGreetingSilence:1000
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Executing [8369@default:4] AGI("SIP/rapidvox-00000032", "VD_amd.agi|8369") in new stack
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Launched AGI Script /var/lib/asterisk/agi-bin/VD_amd.agi
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- AGI Script VD_amd.agi completed, returning 0
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Executing [8369@default:5] AGI("SIP/rapidvox-00000032", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Jun 22 04:18:12] ERROR[23281] utils.c: write() returned error: Broken pipe
[Jun 22 04:18:12] ERROR[23281] utils.c: write() returned error: Broken pipe
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Executing [192*168*000*099*8600051@default:1] Goto("SIP/rapidvox-00000032", "default|8600051|1") in new stack
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Goto (default,8600051,1)
[Jun 22 04:18:12] VERBOSE[23281] logger.c: [Jun 22 04:18:12] -- Executing [8600051@default:1] MeetMe("SIP/rapidvox-00000032", "8600051|F") in new stack
[Jun 22 04:18:15] VERBOSE[23281] logger.c: [Jun 22 04:18:15] == Spawn extension (default, 8600051, 1) exited non-zero on 'SIP/rapidvox-00000032'
[Jun 22 04:18:15] VERBOSE[23281] logger.c: [Jun 22 04:18:15] -- Executing [h@default:1] DeadAGI("SIP/rapidvox-00000032", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----0---------------") in new stack
[Jun 22 04:18:15] VERBOSE[23281] logger.c: [Jun 22 04:18:15] -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses ... ---------- completed, returning 0