Page 2 of 2
Posted:
Mon Sep 18, 2006 12:15 pm
by mflorell
your agiout looks fine, but something is not running properly.
Check the vdautodial.date file for the time you see a CANCEL go through in VDhangup and see if the lead_id of the call shows up as a "dead NA call added to log".
Make sure your call_log.agi script is logging the call as over with an end_epoch and that it actually shows up in the call_log table with the proper caller_code field.
Posted:
Mon Sep 18, 2006 12:35 pm
by enjay
Something is going on with those scripts Im thinking. Here is something that shows up for an ANSWERED call
Database Entry: (NOTICE THE UNIQUEID from Database Vs. AGIOUT logfile).
- Code: Select all
+--------------------+----------------------------------+---------------+-------+-------------+-----------+---------------+----------------------+---------------------+-------------+---------------------+------------+---------------+---------------+
| uniqueid | channel | channel_group | type | server_ip | extension | number_dialed | caller_code | start_time | start_epoch | end_time | end_epoch | length_in_sec | length_in_min |
+--------------------+----------------------------------+---------------+-------+-------------+-----------+---------------+----------------------+---------------------+-------------+---------------------+------------+---------------+---------------+
| 1158599910.7934799 | Local/15053444299@default-394c,1 | | Local | 192.168.0.6 | 8365 | | V0918101828001009127 | 2006-09-18 10:18:36 | 1158599916 | 2006-09-18 10:18:56 | 1158599936 | 20 | 0.33 |
+--------------------+----------------------------------+---------------+-------+-------------+-----------+---------------+----------------------+---------------------+-------------+---------------------+------------+---------------+---------------+
AGI Output: There might be a little overlap here.
- Code: Select all
2006-09-18 10:18:36|call_log.agi|AGI Environment Dump:
2006-09-18 10:18:36|call_log.agi| -- accountcode =
2006-09-18 10:18:36|call_log.agi| -- callerid = 8887112243
2006-09-18 10:18:36|call_log.agi| -- calleridname = V0918101828001009127
2006-09-18 10:18:36|call_log.agi| -- callingani2 = 0
2006-09-18 10:18:36|call_log.agi| -- callingpres = 0
2006-09-18 10:18:36|call_log.agi| -- callingtns = 0
2006-09-18 10:18:36|call_log.agi| -- callington = 0
2006-09-18 10:18:36|call_log.agi| -- channel = Local/15053444299@default-394c,2
2006-09-18 10:18:36|call_log.agi| -- context = default
2006-09-18 10:18:36|call_log.agi| -- dnid = unknown
2006-09-18 10:18:36|call_log.agi| -- enhanced = 0.0
2006-09-18 10:18:36|call_log.agi| -- extension = h
2006-09-18 10:18:36|call_log.agi| -- language = en
2006-09-18 10:18:36|call_log.agi| -- priority = 1
2006-09-18 10:18:36|call_log.agi| -- rdnis = unknown
2006-09-18 10:18:36|call_log.agi| -- request = call_log.agi
2006-09-18 10:18:36|call_log.agi| -- type = Local
2006-09-18 10:18:36|call_log.agi| -- uniqueid = 1158599910.79349
2006-09-18 10:18:36|call_log.agi|AGI Variables: |1158599910.79349|Local/15053444299@default-394c,2|h|Local|V0918101828001009127|
2006-09-18 10:18:36|call_log.agi||CALL HUNG UP|
2006-09-18 10:18:36|call_log.agi||DELETE from live_inbound where uniqueid='1158599910.79349' and server_ip='192.168.0.6'|
2006-09-18 10:18:36|call_log.agi|+++++ CALL LOG HUNGUP: |1158599910.79349|Local/15053444299@default-394c,2|h|2006-09-18 10:18:36|min: |
2006-09-18 10:18:36|call_log.agi|Perl Environment Dump:
2006-09-18 10:18:36|call_log.agi|0|8365
2006-09-18 10:18:36|call_log.agi|AGI Environment Dump:
2006-09-18 10:18:36|call_log.agi| -- accountcode =
2006-09-18 10:18:36|call_log.agi| -- callerid = 8887112243
2006-09-18 10:18:36|call_log.agi| -- calleridname = V0918101828001009127
2006-09-18 10:18:36|call_log.agi| -- callingani2 = 0
2006-09-18 10:18:36|call_log.agi| -- callingpres = 0
2006-09-18 10:18:36|call_log.agi| -- callingtns = 0
2006-09-18 10:18:36|call_log.agi| -- callington = 0
2006-09-18 10:18:36|call_log.agi| -- channel = Local/15053444299@default-394c,1
2006-09-18 10:18:36|call_log.agi| -- context = default
2006-09-18 10:18:36|call_log.agi| -- dnid = unknown
2006-09-18 10:18:36|call_log.agi| -- enhanced = 0.0
2006-09-18 10:18:36|call_log.agi| -- extension = 8365
2006-09-18 10:18:36|call_log.agi| -- language = en
2006-09-18 10:18:36|call_log.agi| -- priority = 1
2006-09-18 10:18:36|call_log.agi| -- rdnis = unknown
2006-09-18 10:18:36|call_log.agi| -- request = call_log.agi
2006-09-18 10:18:36|call_log.agi| -- type = Local
2006-09-18 10:18:36|call_log.agi| -- uniqueid = 1158599910.79348
2006-09-18 10:18:36|call_log.agi|AGI Variables: |1158599910.79348|Local/15053444299@default-394c,1|8365|Local|V0918101828001009127|
2006-09-18 10:18:36|call_log.agi|+++++ CALL LOG START : 2006-09-18 10:18:36
2006-09-18 10:18:36|call_log.agi||INSERT INTO call_log (uniqueid,channel,channel_group,type,server_ip,extension,number_dialed,start_time,start_epoch,end_time,end_epoch,length_in_sec,length_in_min,caller_code) values('1158599910.79348','Local/15053444299@default-394c,1','','Local','192.168.0.6','8365','','2006-09-18 10:18:36','1158599916','','','','','V0918101828001009127')|
2006-09-18 10:18:36|call_log.agi|AGI Environment Dump:
2006-09-18 10:18:36|call_log.agi| -- accountcode =
2006-09-18 10:18:36|call_log.agi| -- callerid = 8887112243
2006-09-18 10:18:36|call_log.agi| -- calleridname = unknown
2006-09-18 10:18:36|call_log.agi| -- callingani2 = 0
2006-09-18 10:18:36|call_log.agi| -- callingpres = 0
2006-09-18 10:18:36|call_log.agi| -- callingtns = 0
2006-09-18 10:18:36|call_log.agi| -- callington = 0
2006-09-18 10:18:36|call_log.agi| -- channel = Local/8500998@default-e3ec,1
2006-09-18 10:18:36|call_log.agi| -- context = default
2006-09-18 10:18:36|call_log.agi| -- dnid = unknown
2006-09-18 10:18:36|call_log.agi| -- enhanced = 0.0
2006-09-18 10:18:36|call_log.agi| -- extension = h
2006-09-18 10:18:36|call_log.agi| -- language = en
2006-09-18 10:18:36|call_log.agi| -- priority = 1
2006-09-18 10:18:36|call_log.agi| -- rdnis = unknown
2006-09-18 10:18:36|call_log.agi| -- request = call_log.agi
2006-09-18 10:18:36|call_log.agi| -- type = Local
2006-09-18 10:18:36|call_log.agi| -- uniqueid = 1158599910.79342
2006-09-18 10:18:36|call_log.agi|AGI Variables: |1158599910.79342|Local/8500998@default-e3ec,1|h|Local|8887112243|
2006-09-18 10:18:36|call_log.agi||CALL HUNG UP|
2006-09-18 10:18:36|call_log.agi||DELETE from live_inbound where uniqueid='1158599910.79342' and server_ip='192.168.0.6'|
2006-09-18 10:18:36|call_log.agi|+++++ CALL LOG HUNGUP: |1158599910.79342|Local/8500998@default-e3ec,1|h|2006-09-18 10:18:36|min: |
2006-09-18 10:18:36|VD_hangup.agi|Perl Environment Dump:
2006-09-18 10:18:36|VD_hangup.agi|0|PRI-----DEBUG-----16-----ANSWER-----6-----0
2006-09-18 10:18:36|VD_hangup.agi|AGI Environment Dump:
2006-09-18 10:18:36|VD_hangup.agi| -- accountcode =
2006-09-18 10:18:36|VD_hangup.agi| -- callerid = 8887112243
2006-09-18 10:18:36|VD_hangup.agi| -- calleridname = V0918101828001009127
2006-09-18 10:18:36|VD_hangup.agi| -- callingani2 = 0
2006-09-18 10:18:36|VD_hangup.agi| -- callingpres = 0
2006-09-18 10:18:36|VD_hangup.agi| -- callingtns = 0
2006-09-18 10:18:36|VD_hangup.agi| -- callington = 0
2006-09-18 10:18:36|VD_hangup.agi| -- channel = Local/15053444299@default-394c,2
2006-09-18 10:18:36|VD_hangup.agi| -- context = default
2006-09-18 10:18:36|VD_hangup.agi| -- dnid = unknown
2006-09-18 10:18:36|VD_hangup.agi| -- enhanced = 0.0
2006-09-18 10:18:36|VD_hangup.agi| -- extension = h
2006-09-18 10:18:36|VD_hangup.agi| -- language = en
2006-09-18 10:18:36|VD_hangup.agi| -- priority = 2
2006-09-18 10:18:36|VD_hangup.agi| -- rdnis = unknown
2006-09-18 10:18:36|VD_hangup.agi| -- request = VD_hangup.agi
2006-09-18 10:18:36|VD_hangup.agi| -- type = Local
2006-09-18 10:18:36|VD_hangup.agi| -- uniqueid = 1158599910.79349
2006-09-18 10:18:36|VD_hangup.agi|AGI Variables: |1158599910.79349|Local/15053444299@default-394c,2|h|Local|V0918101828001009127|
2006-09-18 10:18:36|VD_hangup.agi|VD_hangup : V0918101828001009127 Local/15053444299@default-394c,2 2 1009127
2006-09-18 10:18:36|VD_hangup.agi|-- VDhangup Local DEBUG: |PRI|V0918101828001009127|ANSWER|16|
2006-09-18 10:18:36|VD_hangup.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 2
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|Perl Environment Dump:
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|0|8365
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|callerID changed: V0918101828001009127
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|AGI Environment Dump:
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- accountcode =
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- callerid = 8887112243
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- calleridname = V0918101828001009127
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- callingani2 = 0
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- callingpres = 0
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- callingtns = 0
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- callington = 0
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- channel = Zap/9-1
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- context = default
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- dnid = unknown
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- enhanced = 0.0
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- extension = 8365
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- language = en
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- priority = 2
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- rdnis = unknown
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- request = agi-VDAD_LB_transfer.agi
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- type = Zap
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi| -- uniqueid = 1158599910.79348
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|AGI Variables: |1158599910.79348|Zap/9-1|8365|Zap|V0918101828001009127|V0918101828001009127|2|
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|+++++ VDAD START : |1009127|2006-09-18 10:18:36|1.2|2|
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|-- VDAD : |1|update of vac table: V0918101828001009127
|UPDATE vicidial_auto_calls set uniqueid='1158599910.79348', channel='Zap/9-1',status='LIVE' where callerid='V0918101828001009127' order by call_time desc limit 1;|
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi||INSERT INTO vicidial_log (uniqueid,lead_id,campaign_id,call_date,start_epoch,status,phone_code,phone_number,user,processed) values('1158599910.79348','1009127','1003','2006-09-18 10:18:36','1158599916','QUEUE','','5053444299','VDAD','N')|
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|-- VDAD : |1009127|1009127|insert to vicidial_log: 1158599910.79348
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi||SELECT count(*) FROM vicidial_auto_calls where status = 'LIVE' and campaign_id = '1003' and call_time < "2006-09-18 10:18:28" and lead_id != '1009127';|
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|-- VDAD get agent: |1|update of vla table: 1003|192.168.0.6
|UPDATE vicidial_live_agents set status='QUEUE',lead_id='1009127',uniqueid='1158599910.79348', channel='Zap/9-1', call_server_ip='192.168.0.6', callerid='V0918101828001009127' where status = 'READY' and campaign_id='1003' and last_update_time > '19691231165955' order by last_call_finish limit 1;|
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi||SELECT conf_exten,user,extension,server_ip FROM vicidial_live_agents where status = 'QUEUE' and campaign_id='1003' and callerid='V0918101828001009127' and channel='Zap/9-1' order by last_call_time limit 1;|
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|-- VDAD XFER : |1|update of vac table: V0918101828001009127
|UPDATE vicidial_auto_calls set status='XFER' where callerid='V0918101828001009127';|
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|exiting the VDAD app, transferring call to
2006-09-18 10:18:36|agi-VDAD_LB_transfer.agi|XXXXXXXXXX VDAD transferred: start|stop 2006-09-18 10:18:36|2006-09-18 10:18:36
As you can see the UniqueID that is logged in the database is CLOSE but different from that of the AGI output.
database: 1158599910.7934799
AGIout: 1158599910.79349 (where is the 7 & 9 in the end of it).
Anything with a CANCEL does not show up at all in the database (based on caller_code) I can lookup every ANSWER and they show up but no CANCELS.
-Art
Posted:
Mon Sep 18, 2006 2:58 pm
by mflorell
The inconsistency is because the data is stored as a float instead of a string.
What version of MySQL are you using?
You could try changing it to a VARCHAR like we do for BRI-stufft installations:
http://astguiclient.sourceforge.net/faq.html#04040
Make sure system is not active when you do those updates though, it takes a while to do them on a system with a lot of calls in the call_log and vicidial_log.
Posted:
Mon Sep 18, 2006 3:34 pm
by enjay
mysql Ver 14.7 Distrib 4.1.20, for redhat-linux-gnu (i386) using readline 4.3
Posted:
Mon Sep 18, 2006 3:59 pm
by enjay
In the vicidial_auto_calls table I notice that all of the CANCEL calls have a uniqueid of NULL
- Code: Select all
+--------------+-------------+-------------+--------+---------+----------+----------------------+---------+------------+--------------+---------------------+-----------+
| auto_call_id | server_ip | campaign_id | status | lead_id | uniqueid | callerid | channel | phone_code | phone_number | call_time | call_type |
+--------------+-------------+-------------+--------+---------+----------+----------------------+---------+------------+--------------+---------------------+-----------+
| 833339 | 192.168.0.5 | 1002 | SENT | 178148 | NULL | V0918135502000178148 | NULL | | 9517807625 | 2006-09-18 13:55:02 | OUT |
+--------------+-------------+-------------+--------+---------+----------+----------------------+---------+------------+--------------+---------------------+-----------+
Posted:
Mon Sep 18, 2006 10:24 pm
by enjay
I'll get back at this tomorrow, I've been working on this 16 hours today I've tried everything I can think of and everything you've asked with the same results.
I hate to rebuild the whole thing, but Im at my whits end here..
Posted:
Tue Sep 19, 2006 5:34 am
by mflorell
Changing to VARCHAR did nothing to help?
Posted:
Tue Sep 19, 2006 10:17 am
by enjay
Going to do some more testing this morning with it though last night appeared as though nothing had changed, I still saw no NA's and plenty of cancels.
I wonder if its having issues interpretting the CANCEL vs DROP vs NOANSWER vs CHANUNAVAIL vs ANSWER
Posted:
Tue Sep 19, 2006 11:12 am
by mflorell
I have 10s of thousands of CANCEL NAs in my vicidial_log every day so I know it does log them here. I am using almost all PRIs.
Posted:
Tue Sep 19, 2006 11:41 am
by enjay
I have 2 PRI's and 3 E&M Wink T1's though problem exists across the board. I just cant pinpoint where the problem is actually.. I see the agiout see's cancels.. but the vdauto script doesnt turn them into NA's.
Posted:
Tue Sep 19, 2006 11:56 am
by enjay
I just copied all the default astguiclient stuff
"agc/vicidial.php" etc etc etc so that I could rule out that maybe I had messed something up in my code that could have cause it but I experience the same thing.. I have not modified any of the agi stuff so I doubt thats the issue..
I upgraded to MySQL 5.0.24a last night to see if that would fix anything.
Posted:
Tue Sep 19, 2006 12:06 pm
by mflorell
You kind of have that reversed, this is an issue with the agi scripts or the perl scripts or possibly a server setting. This would have nothing to do with any PHP scripts since the CANCEL calls never make it to any of those.
Posted:
Tue Sep 19, 2006 12:09 pm
by enjay
yea I figured as such it was just something I "HAD" to do for self re-assurance that I didnt break something
could this have something to do with it?
in my vicidial_auto_calls the CANCEL calls come up with
- Code: Select all
+--------------+-------------+-------------+--------+---------+----------+----------------------+---------+------------+--------------+---------------------+-----------+
| auto_call_id | server_ip | campaign_id | status | lead_id | uniqueid | callerid | channel | phone_code | phone_number | call_time | call_type |
+--------------+-------------+-------------+--------+---------+----------+----------------------+---------+------------+--------------+---------------------+-----------+
| 847319 | 192.168.0.6 | 1003 | SENT | 948670 | | V0919100547000948670 | NULL | | 5056238349 | 2006-09-19 10:05:47 | OUT |
+--------------+-------------+-------------+--------+---------+----------+----------------------+---------+------------+--------------+---------------------+-----------+
while the answered calls come up with:
- Code: Select all
+--------------+-------------+-------------+--------+---------+--------------------+----------------------+----------+------------+--------------+---------------------+-----------+
| auto_call_id | server_ip | campaign_id | status | lead_id | uniqueid | callerid | channel | phone_code | phone_number | call_time | call_type |
+--------------+-------------+-------------+--------+---------+--------------------+----------------------+----------+------------+--------------+---------------------+-----------+
| 217922 | 192.168.0.6 | 1003 | XFER | 758776 | 1154558807.1439867 | V0802154646000758776 | Zap/3-1 | | 5056273345 | 2006-08-02 15:46:46 | OUT |
+--------------+-------------+-------------+--------+---------+--------------------+----------------------+----------+------------+--------------+---------------------+-----------+
15 rows in set (0.00 sec)
Posted:
Tue Sep 19, 2006 12:29 pm
by mflorell
That does look like mine for the ones that become CANCELs. But as soon as they are hungup the AST_VDauto_dial script deletes them right away when they are detected as hungup.
Are there any corresponding call_log table records for those caller_codes?
Posted:
Tue Sep 19, 2006 12:32 pm
by enjay
There is not one for any of the CANCELS but yes for the ANSWERS
- Code: Select all
mysql> select * from call_log where caller_code="V0919100547000948670";
Empty set (0.00 sec)
mysql> select * from call_log where caller_code="V0802154646000758776";
+--------------------+----------------------------------+---------------+-------+-------------+-----------+---------------+----------------------+---------------------+-------------+---------------------+-----------+---------------+---------------+
| uniqueid | channel | channel_group | type | server_ip | extension | number_dialed | caller_code | start_time | start_epoch | end_time | end_epoch | length_in_sec | length_in_min |
+--------------------+----------------------------------+---------------+-------+-------------+-----------+---------------+----------------------+---------------------+-------------+---------------------+-----------+---------------+---------------+
| 1154558807.1439867 | Local/15056273345@default-8c6c,1 | | Local | 192.168.0.6 | 8365 | | V0802154646000758776 | 2006-08-02 15:47:04 | 1154558824 | 0000-00-00 00:00:00 | 0 | 0 | 0.00 |
+--------------------+----------------------------------+---------------+-------+-------------+-----------+---------------+----------------------+---------------------+-------------+---------------------+-----------+---------------+---------------+
Posted:
Tue Sep 19, 2006 2:34 pm
by mflorell
can you post some Asterisk CLI output with agi output set to STDERR of a call being initiated and Dialed so we can see what call_log.agi is doing with the log for your calls?
Posted:
Tue Sep 19, 2006 3:33 pm
by mflorell
You should be seeing a LOT more output that that if you are in the Real Asterisk CLI and you have AGIOUTPUT set to STDERR.
What version of the agi scripts are you running?
Posted:
Tue Sep 19, 2006 3:53 pm
by enjay
yea Im a goob, was in asterisk -r.. ok created a script file for it
http://www.magmanetworks.com/script.txt
-enjay
Posted:
Tue Sep 19, 2006 6:54 pm
by enjay
Or here is an instance I pulled out of the script.txt file where I receive a BUSY from the asterisk server yet it doesnt get placed in the database. I know we have been talking about CANCEL's in general but anything other than ANSWERS arent working.
- Code: Select all
-- Executing DeadAGI("Local/6022679357@default-b8b1,2", "call_log.agi|h") in
new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/call_log.agi
2006-09-19 13:44:25|call_log.agi|AGI Environment Dump:
2006-09-19 13:44:25|call_log.agi| -- accountcode =
2006-09-19 13:44:25|call_log.agi| -- callerid = 6233888899
2006-09-19 13:44:25|call_log.agi| -- calleridname = V0919134413000662775
2006-09-19 13:44:25|call_log.agi| -- callingani2 = 0
2006-09-19 13:44:25|call_log.agi| -- callingpres = 0
2006-09-19 13:44:25|call_log.agi| -- callingtns = 0
2006-09-19 13:44:25|call_log.agi| -- callington = 0
2006-09-19 13:44:25|call_log.agi| -- channel = Local/6022679357@default-b8b1,2
2006-09-19 13:44:25|call_log.agi| -- context = default
2006-09-19 13:44:25|call_log.agi| -- dnid = unknown
2006-09-19 13:44:25|call_log.agi| -- enhanced = 0.0
2006-09-19 13:44:25|call_log.agi| -- extension = h
2006-09-19 13:44:25|call_log.agi| -- language = en
2006-09-19 13:44:25|call_log.agi| -- priority = 1
2006-09-19 13:44:25|call_log.agi| -- rdnis = unknown
2006-09-19 13:44:25|call_log.agi| -- request = call_log.agi
2006-09-19 13:44:25|call_log.agi| -- type = Local
2006-09-19 13:44:25|call_log.agi| -- uniqueid = 1158698654.12851
2006-09-19 13:44:25|call_log.agi|AGI Variables: |1158698654.12851|Local/6022679357@default-b8b1,2|h|Local|V0919134413000662775|
2006-09-19 13:44:25|call_log.agi||CALL HUNG UP|
2006-09-19 13:44:25|call_log.agi||DELETE from live_inbound where uniqueid='1158698654.12851' and server_ip='192.168.0.5'|
2006-09-19 13:44:25|call_log.agi|+++++ CALL LOG HUNGUP: |1158698654.12851|Local/6022679357@default-b8b1,2|h|2006-09-19 13:44:25|min: |
-- AGI Script call_log.agi completed, returning 0
-- Executing DeadAGI("Local/6022679357@default-b8b1,2", "VD_hangup.agi|PRI-----NODEBUG-----17-----BUSY----------") in new stack
-- Launched AGI Script /var/lib/asterisk/agi-bin/VD_hangup.agi
2006-09-19 13:44:25|VD_hangup.agi|Perl Environment Dump:
2006-09-19 13:44:25|VD_hangup.agi|0|PRI-----NODEBUG-----17-----BUSY----------
2006-09-19 13:44:25|VD_hangup.agi|AGI Environment Dump:
2006-09-19 13:44:25|VD_hangup.agi| -- accountcode =
2006-09-19 13:44:25|VD_hangup.agi| -- callerid = 6233888899
2006-09-19 13:44:25|VD_hangup.agi| -- calleridname = V0919134413000662775
2006-09-19 13:44:25|VD_hangup.agi| -- callingani2 = 0
2006-09-19 13:44:25|VD_hangup.agi| -- callingpres = 0
2006-09-19 13:44:25|VD_hangup.agi| -- callingtns = 0
2006-09-19 13:44:25|VD_hangup.agi| -- callington = 0
2006-09-19 13:44:25|VD_hangup.agi| -- channel = Local/6022679357@default-b8b1,2
2006-09-19 13:44:25|VD_hangup.agi| -- context = default
2006-09-19 13:44:25|VD_hangup.agi| -- dnid = unknown
2006-09-19 13:44:25|VD_hangup.agi| -- enhanced = 0.0
2006-09-19 13:44:25|VD_hangup.agi| -- extension = h
2006-09-19 13:44:25|VD_hangup.agi| -- language = en
2006-09-19 13:44:25|VD_hangup.agi| -- priority = 2
2006-09-19 13:44:25|VD_hangup.agi| -- rdnis = unknown
2006-09-19 13:44:25|VD_hangup.agi| -- request = VD_hangup.agi
2006-09-19 13:44:25|VD_hangup.agi| -- type = Local
2006-09-19 13:44:25|VD_hangup.agi| -- uniqueid = 1158698654.12851
2006-09-19 13:44:25|VD_hangup.agi|AGI Variables: |1158698654.12851|Local/6022679357@default-b8b1,2|h|Local|V0919134413000662775|
2006-09-19 13:44:25|VD_hangup.agi|DEBUG: NODEBUG
2006-09-19 13:44:25|VD_hangup.agi|VD_hangup : V0919134413000662775 Local/6022679357@default-b8b1,2 2 662775
2006-09-19 13:44:25|VD_hangup.agi||UPDATE vicidial_auto_calls set status='BUSY' where callerid = 'V0919134413000662775';|
2006-09-19 13:44:25|VD_hangup.agi|-- VDAC update: |1|662775
2006-09-19 13:44:25|VD_hangup.agi||UPDATE vicidial_list set status='B' where lead_id = '662775';|
2006-09-19 13:44:25|VD_hangup.agi|-- VDAD vicidial_list update: |1|662775
2006-09-19 13:44:25|VD_hangup.agi||UPDATE vicidial_log set status='B' where uniqueid = '1158698654.12851';|
2006-09-19 13:44:25|VD_hangup.agi|-- VDAD vicidial_log update: |0E0|1158698654.12851|
2006-09-19 13:44:25|VD_hangup.agi|+++++ VDAD START LOCAL CHANNEL: EXITING- 2
-- AGI Script VD_hangup.agi completed, returning 0
when I do a select * from vicidial_log where uniqueid="1158698654.12851";
I receive an empty set also in the call_log.
more examples to follow.
Posted:
Tue Sep 19, 2006 8:17 pm
by mflorell
Do you have a call_log.agi entry directly before your "Dial" entry in extensions.conf for NXXNXXXXXX?
It looks like it's not there and that for some reason you might only have a call_log.agi entry at the beginning of your 8365 exten.
Posted:
Tue Sep 19, 2006 9:27 pm
by enjay
That was it man.. UN $*#*@($ BELIEVABLE!
Have I told you today that I love you? "in a non homosexual way".
Posted:
Tue Sep 19, 2006 10:05 pm
by mflorell
Well thanks for that
I'm glad it's working for you now!
Posted:
Tue Sep 19, 2006 10:32 pm
by enjay
ME TOO BRO meeeeeeeee too!
Posted:
Wed Sep 20, 2006 12:36 pm
by enjay
So that fixed that problem but now Im getting HUGE load avg's because of it.
10:35:28 up 22:28, 1 user, load average: 45.62, 18.60, 15.74
I typically run in the 2.5-3.0 range before I added that. Thoughts?
-enjay
Posted:
Wed Sep 20, 2006 12:51 pm
by mflorell
that makes no sense, what machine are those loadavgs from?
what does top show?
Posted:
Wed Sep 20, 2006 2:02 pm
by enjay
These are on the main VICIDIAL Server that the people are calling out of.
its a 3.4ghz with Hyperthreading
2gb Ram
15k SCSI drives
here is a snippet of top over a 15 second period after I put the call_log.agi before my dial string. Note this continually goes up I've seen it as high as 45.xx load avg as you see above..
- Code: Select all
top - 12:00:20 up 23:53, 1 user, load average: 8.73, 3.17, 1.93
Tasks: 123 total, 34 running, 89 sleeping, 0 stopped, 0 zombie
Cpu(s): 67.3% us, 23.5% sy, 0.0% ni, 8.0% id, 0.0% wa, 0.3% hi, 0.8% si
Mem: 2074900k total, 2004332k used, 70568k free, 32932k buffers
Swap: 0k total, 0k used, 0k free, 1697888k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2411 root -11 0 62280 22m 5164 S 34.2 1.1 93:13.27 asterisk
2836 root 15 0 11252 6944 2536 S 9.3 0.3 29:41.98 AST_update.pl
10969 root 15 0 11308 5000 2500 S 6.6 0.2 0:00.20 agi-VDAD_LB_tra
10819 root 20 0 5948 4336 1800 S 4.0 0.2 0:00.12 AST_send_action
10899 root 20 0 4960 3064 1484 R 3.6 0.1 0:00.12 AST_send_action
10829 root 20 0 4828 2884 1484 R 3.3 0.1 0:00.10 AST_send_action
10832 root 20 0 5952 4320 1784 R 3.3 0.2 0:00.19 AST_send_action
10858 root 20 0 5512 3580 1568 R 3.3 0.2 0:00.11 AST_send_action
10743 root 20 0 5952 4312 1792 S 3.0 0.2 0:00.18 AST_send_action
10790 root 20 0 4964 2996 1492 R 3.0 0.1 0:00.09 AST_send_action
10798 root 20 0 4964 2988 1484 R 3.0 0.1 0:00.09 AST_send_action
10808 root 20 0 5952 4284 1776 S 3.0 0.2 0:00.18 AST_send_action
10827 root 20 0 5952 4316 1792 S 3.0 0.2 0:00.19 AST_send_action
10855 root 19 0 7236 3400 1680 R 3.0 0.2 0:00.09 VD_hangup.agi
10877 root 23 0 4960 3068 1484 R 3.0 0.1 0:00.09 AST_send_action
10889 root 20 0 4964 2972 1484 R 3.0 0.1 0:00.09 AST_send_action
10944 root 19 0 5776 3944 1620 R 3.0 0.2 0:00.09 AST_send_action
10995 root 19 0 10928 4220 2144 R 3.0 0.2 0:00.09 call_log.agi
10917 root 19 0 5952 4308 1792 S 2.7 0.2 0:00.09 AST_send_action
10770 root 20 0 5948 4280 1776 S 2.3 0.2 0:00.18 AST_send_action
10814 root 20 0 5952 4316 1792 S 2.0 0.2 0:00.19 AST_send_action
10763 root 20 0 5952 4312 1792 S 1.7 0.2 0:00.16 AST_send_action
2750 root 15 0 11892 7612 2528 S 1.3 0.4 3:14.84 AST_manager_lis
2759 root 16 0 9084 4792 2448 S 1.3 0.2 2:42.76 AST_manager_sen
10896 root 19 0 5948 4308 1792 S 1.3 0.2 0:00.12 AST_send_action
10931 root 20 0 6204 2372 1604 R 1.3 0.1 0:00.04 call_log.agi
10935 root 19 0 6204 2256 1492 R 1.3 0.1 0:00.04 call_log.agi
10951 root 19 0 4836 2912 1484 R 1.3 0.1 0:00.04 AST_send_action
10999 root 19 0 11016 4692 2516 R 1.3 0.2 0:00.04 call_log.agi
11007 root 20 0 4144 2052 1312 R 1.3 0.1 0:00.04 AST_send_action
11009 root 20 0 4960 3068 1484 R 1.3 0.1 0:00.04 AST_send_action
154 root 15 0 0 0 0 S 1.0 0.0 0:00.11 kswapd0
2337 root 16 0 5128 1892 1088 S 1.0 0.1 1:38.51 screen
10965 root 20 0 4432 2484 1480 R 1.0 0.1 0:00.03 AST_send_action
2796 root 16 0 12264 7988 2472 S 0.7 0.4 3:59.83 AST_VDauto_dial
2749 root 15 0 2696 1172 864 S 0.3 0.1 0:23.54 screen
7400 root 16 0 7412 2316 1860 R 0.3 0.1 0:00.10 sshd
top - 12:00:26 up 23:53, 1 user, load average: 10.76, 3.68, 2.11
Tasks: 137 total, 36 running, 101 sleeping, 0 stopped, 0 zombie
Cpu(s): 64.7% us, 28.0% sy, 0.0% ni, 6.4% id, 0.0% wa, 0.0% hi, 0.8% si
Mem: 2074900k total, 1996376k used, 78524k free, 28600k buffers
Swap: 0k total, 0k used, 0k free, 1664260k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2411 root -11 0 62300 22m 5164 S 36.9 1.1 93:15.38 asterisk
11160 root 15 0 11308 5000 2504 S 6.9 0.2 0:00.21 agi-VDAD_LB_tra
2836 root 17 0 11252 6944 2536 S 5.3 0.3 29:42.46 AST_update.pl
11078 root 20 0 5112 3228 1552 R 3.3 0.2 0:00.11 AST_send_action
11083 root 19 0 7292 3404 1712 R 3.3 0.2 0:00.12 call_log.agi
11097 root 19 0 6972 3128 1680 R 3.3 0.2 0:00.10 VD_hangup.agi
10938 root 20 0 4960 3104 1524 R 3.0 0.1 0:00.09 AST_send_action
10975 root 20 0 5096 3160 1528 R 3.0 0.2 0:00.10 AST_send_action
11005 root 20 0 5948 4312 1792 S 3.0 0.2 0:00.18 AST_send_action
11009 root 20 0 5948 4312 1792 S 3.0 0.2 0:00.13 AST_send_action
2750 root 15 0 11892 7612 2528 S 2.0 0.4 3:14.94 AST_manager_lis
10889 root 20 0 5952 4312 1792 S 2.0 0.2 0:00.15 AST_send_action
10991 root 20 0 5948 4308 1792 S 2.0 0.2 0:00.16 AST_send_action
11007 root 20 0 5948 4312 1792 S 2.0 0.2 0:00.10 AST_send_action
11093 root 19 0 5948 4312 1792 S 2.0 0.2 0:00.15 AST_send_action
11096 root 19 0 5948 4336 1796 S 1.6 0.2 0:00.15 AST_send_action
11137 root 19 0 4696 2756 1492 R 1.3 0.1 0:00.04 AST_send_action
11175 root 19 0 6204 2236 1488 R 1.3 0.1 0:00.04 call_log.agi
11183 root 19 0 6208 2240 1488 R 1.3 0.1 0:00.04 call_log.agi
11219 root 19 0 4436 2456 1480 R 1.3 0.1 0:00.04 AST_send_action
2759 root 16 0 9084 4792 2448 S 1.0 0.2 2:42.81 AST_manager_sen
154 root 15 0 0 0 0 S 0.7 0.0 0:00.14 kswapd0
2796 root 16 0 12264 7988 2472 S 0.7 0.4 3:59.89 AST_VDauto_dial
10973 root 19 0 10760 3888 1900 R 0.7 0.2 0:00.11 call_log.agi
2337 root 16 0 5128 1892 1088 S 0.3 0.1 1:38.53 screen
8824 root 16 0 2024 1016 784 R 0.3 0.0 0:00.32 top
10770 root 16 0 5948 4316 1792 S 0.3 0.2 0:00.19 AST_send_action
10798 root 20 0 5952 4312 1792 S 0.3 0.2 0:00.20 AST_send_action
10899 root 20 0 5948 4304 1792 S 0.3 0.2 0:00.13 AST_send_action
10944 root 19 0 5952 4344 1800 S 0.3 0.2 0:00.10 AST_send_action
10989 root 20 0 5952 4316 1792 S 0.3 0.2 0:00.11 AST_send_action
11104 root 19 0 5928 1624 1196 R 0.3 0.1 0:00.01 VD_hangup.agi
11132 root 19 0 5928 1656 1200 R 0.3 0.1 0:00.01 call_log.agi
11142 root 19 0 5928 1684 1204 R 0.3 0.1 0:00.01 call_log.agi
11177 root 19 0 3752 1428 1060 R 0.3 0.1 0:00.01 AST_send_action
11189 root 20 0 6204 2236 1488 R 0.3 0.1 0:00.01 call_log.agi
1 root 15 0 1748 600 520 S 0.0 0.0 0:03.51 init
top - 12:00:32 up 23:53, 1 user, load average: 12.54, 4.16, 2.27
Tasks: 135 total, 37 running, 98 sleeping, 0 stopped, 0 zombie
Cpu(s): 61.9% us, 28.8% sy, 0.0% ni, 7.9% id, 0.0% wa, 0.3% hi, 1.0% si
Mem: 2074900k total, 1986096k used, 88804k free, 28608k buffers
Swap: 0k total, 0k used, 0k free, 1664252k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2411 root -11 0 62316 22m 5164 S 42.8 1.1 93:17.90 asterisk
11172 root 19 0 10884 4432 2324 R 4.6 0.2 0:00.15 call_log.agi
11396 root 18 0 7248 3320 1684 R 4.0 0.2 0:00.12 call_log.agi
11219 root 19 0 5952 4308 1792 S 3.3 0.2 0:00.14 AST_send_action
11270 root 19 0 6988 3116 1680 R 3.3 0.2 0:00.10 call_log.agi
11312 root 15 0 11304 5004 2504 S 3.3 0.2 0:00.10 agi-VDAD_LB_tra
11047 root 21 0 5952 4332 1792 S 3.0 0.2 0:00.19 AST_send_action
11309 root 19 0 11088 4532 2236 R 3.0 0.2 0:00.09 VD_hangup.agi
11315 root 19 0 5948 4312 1792 S 2.7 0.2 0:00.08 AST_send_action
11146 root 19 0 10880 4428 2324 R 2.0 0.2 0:00.16 call_log.agi
11150 root 19 0 11012 4572 2408 R 2.0 0.2 0:00.15 call_log.agi
2750 root 16 0 11892 7612 2528 S 1.7 0.4 3:15.04 AST_manager_lis
10975 root 20 0 5952 4312 1792 S 1.7 0.2 0:00.15 AST_send_action
11078 root 20 0 5948 4312 1792 S 1.7 0.2 0:00.16 AST_send_action
11186 root 19 0 10884 4460 2328 R 1.7 0.2 0:00.15 call_log.agi
11257 root 19 0 5952 4308 1792 S 1.7 0.2 0:00.05 AST_send_action
2796 root 16 0 12264 7988 2472 S 1.3 0.4 3:59.93 AST_VDauto_dial
11319 root 20 0 5904 4100 1620 R 1.3 0.2 0:00.04 AST_send_action
11347 root 19 0 6204 2236 1488 R 1.3 0.1 0:00.04 call_log.agi
11375 root 19 0 6196 1984 1288 R 1.3 0.1 0:00.04 VD_hangup.agi
2337 root 15 0 5128 1892 1088 S 1.0 0.1 1:38.59 screen
2759 root 16 0 9084 4792 2448 S 1.0 0.2 2:42.84 AST_manager_sen
10938 root 20 0 5948 4308 1792 S 1.0 0.2 0:00.12 AST_send_action
8824 root 16 0 2024 1016 784 R 0.7 0.0 0:00.35 top
11353 root 19 0 5932 1660 1200 R 0.7 0.1 0:00.02 call_log.agi
11183 root 19 0 10884 4440 2328 R 0.3 0.2 0:00.15 call_log.agi
11295 root 19 0 5804 1532 1188 R 0.3 0.1 0:00.01 VD_hangup.agi
11324 root 19 0 5796 1528 1176 R 0.3 0.1 0:00.01 call_log.agi
11337 root 20 0 4148 2044 1312 R 0.3 0.1 0:00.01 AST_send_action
11349 root 20 0 4016 1772 1172 R 0.3 0.1 0:00.01 AST_send_action
11380 root 19 0 5932 1620 1196 R 0.3 0.1 0:00.01 VD_hangup.agi
11401 root 19 0 3884 1712 1172 R 0.3 0.1 0:00.01 AST_send_action
1 root 15 0 1748 600 520 S 0.0 0.0 0:03.51 init
2 root RT 0 0 0 0 S 0.0 0.0 0:00.51 migration/0
3 root 34 19 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/0
4 root RT 0 0 0 0 S 0.0 0.0 0:00.00 watchdog/0
5 root RT 0 0 0 0 S 0.0 0.0 0:00.50 migration/1
top - 12:00:41 up 23:53, 1 user, load average: 14.07, 4.77, 2.49
Tasks: 110 total, 25 running, 85 sleeping, 0 stopped, 0 zombie
Cpu(s): 59.9% us, 31.3% sy, 0.0% ni, 7.5% id, 0.0% wa, 0.2% hi, 1.2% si
Mem: 2074900k total, 1948836k used, 126064k free, 28616k buffers
Swap: 0k total, 0k used, 0k free, 1664244k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2411 root -11 0 62264 22m 5164 S 47.4 1.1 93:21.86 asterisk
11483 root 19 0 5948 4308 1792 S 5.6 0.2 0:00.18 AST_send_action
11465 root 20 0 5952 4336 1800 S 5.3 0.2 0:00.16 AST_send_action
11565 root 19 0 7668 3836 1768 R 3.6 0.2 0:00.11 VD_hangup.agi
11614 root 19 0 5772 3976 1612 R 3.3 0.2 0:00.10 AST_send_action
11493 root 19 0 5948 4312 1792 S 3.0 0.2 0:00.19 AST_send_action
11498 root 19 0 6852 3012 1680 R 3.0 0.1 0:00.09 call_log.agi
11581 root 19 0 5904 4092 1620 R 3.0 0.2 0:00.09 AST_send_action
11599 root 20 0 5772 3976 1620 R 3.0 0.2 0:00.09 AST_send_action
11612 root 19 0 6852 2968 1680 R 3.0 0.1 0:00.09 call_log.agi
11481 root 20 0 5904 4076 1616 R 2.7 0.2 0:00.19 AST_send_action
11561 root 20 0 10884 4432 2324 R 2.7 0.2 0:00.08 call_log.agi
11628 root 18 0 6460 2648 1680 R 2.3 0.1 0:00.07 call_log.agi
11462 root 20 0 4828 2932 1484 R 2.0 0.1 0:00.09 AST_send_action
2750 root 16 0 11892 7612 2528 S 1.3 0.4 3:15.16 AST_manager_lis
2759 root 15 0 9084 4792 2448 S 1.3 0.2 2:42.92 AST_manager_sen
2836 root 15 0 11252 6944 2536 S 1.3 0.3 29:43.16 AST_update.pl
2796 root 16 0 12264 7988 2472 S 1.0 0.4 4:00.02 AST_VDauto_dial
2337 root 16 0 5128 1892 1088 S 0.7 0.1 1:38.64 screen
11535 root 16 0 2024 1000 784 R 0.7 0.0 0:00.03 top
11486 root 19 0 5948 4340 1800 S 0.3 0.2 0:00.11 AST_send_action
11567 root 20 0 3880 1692 1172 R 0.3 0.1 0:00.01 AST_send_action
11588 root 20 0 5952 4316 1792 S 0.3 0.2 0:00.01 AST_send_action
11604 root 20 0 4016 1916 1240 R 0.3 0.1 0:00.01 AST_send_action
1 root 16 0 1748 600 520 S 0.0 0.0 0:03.51 init
2 root RT 0 0 0 0 S 0.0 0.0 0:00.51 migration/0
3 root 34 19 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/0
4 root RT 0 0 0 0 S 0.0 0.0 0:00.00 watchdog/0
5 root RT 0 0 0 0 S 0.0 0.0 0:00.50 migration/1
6 root 34 19 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/1
7 root RT 0 0 0 0 S 0.0 0.0 0:00.00 watchdog/1
8 root 10 -5 0 0 0 S 0.0 0.0 0:00.01 events/0
9 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 events/1
10 root 17 -5 0 0 0 S 0.0 0.0 0:00.00 khelper
11 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 kthread
14 root 20 -5 0 0 0 S 0.0 0.0 0:00.00 kacpid
91 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 kblockd/0
top - 12:00:50 up 23:53, 1 user, load average: 16.40, 5.57, 2.77
Tasks: 120 total, 34 running, 86 sleeping, 0 stopped, 0 zombie
Cpu(s): 67.0% us, 24.5% sy, 0.0% ni, 7.0% id, 0.0% wa, 0.3% hi, 1.2% si
Mem: 2074900k total, 1963948k used, 110952k free, 28640k buffers
Swap: 0k total, 0k used, 0k free, 1664740k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2411 root -11 0 62296 22m 5164 S 33.2 1.1 93:25.28 asterisk
11854 root 16 0 11308 5004 2500 S 6.6 0.2 0:00.20 agi-VDAD_LB_tra
11895 root 18 0 5948 4332 1796 S 6.6 0.2 0:00.20 AST_send_action
11832 root 19 0 11176 4412 2144 R 4.6 0.2 0:00.14 VD_hangup.agi
11898 root 18 0 5948 4308 1792 S 4.3 0.2 0:00.13 AST_send_action
11656 root 22 0 4964 2988 1484 R 3.3 0.1 0:00.10 AST_send_action
11820 root 19 0 5248 3304 1552 R 3.3 0.2 0:00.11 AST_send_action
11830 root 19 0 5092 3156 1528 R 3.3 0.2 0:00.11 AST_send_action
11863 root 19 0 7104 3284 1680 R 3.3 0.2 0:00.10 VD_hangup.agi
11759 root 19 0 6988 3108 1680 R 3.0 0.1 0:00.09 call_log.agi
11803 root 20 0 5904 4100 1620 R 3.0 0.2 0:00.09 AST_send_action
11900 root 19 0 5244 3384 1552 R 3.0 0.2 0:00.09 AST_send_action
11699 root 19 0 5948 4308 1792 S 2.7 0.2 0:00.18 AST_send_action
2836 root 16 0 11252 6944 2536 S 2.3 0.3 29:43.83 AST_update.pl
11810 root 19 0 5948 4336 1796 S 2.3 0.2 0:00.07 AST_send_action
2796 root 15 0 12264 7988 2472 S 1.7 0.4 4:00.18 AST_VDauto_dial
11737 root 19 0 10884 4444 2328 R 1.7 0.2 0:00.15 call_log.agi
2750 root 16 0 11892 7612 2528 S 1.0 0.4 3:15.27 AST_manager_lis
2759 root 15 0 9084 4792 2448 S 1.0 0.2 2:43.00 AST_manager_sen
11768 root 19 0 11132 4764 2408 R 1.0 0.2 0:00.03 VD_hangup.agi
11798 root 20 0 5092 3160 1524 R 1.0 0.2 0:00.03 AST_send_action
11816 root 20 0 5952 4336 1800 S 1.0 0.2 0:00.03 AST_send_action
2337 root 16 0 5128 1892 1088 S 0.7 0.1 1:38.70 screen
1 root 15 0 1748 600 520 S 0.3 0.0 0:03.52 init
11567 root 16 0 5948 4316 1792 S 0.3 0.2 0:00.19 AST_send_action
11570 root 16 0 5948 4316 1792 S 0.3 0.2 0:00.16 AST_send_action
11614 root 16 0 5948 4316 1792 S 0.3 0.2 0:00.13 AST_send_action
11882 root 20 0 3880 1656 1172 R 0.3 0.1 0:00.01 AST_send_action
11886 root 19 0 3748 1420 1060 R 0.3 0.1 0:00.01 AST_send_action
2 root RT 0 0 0 0 S 0.0 0.0 0:00.51 migration/0
3 root 34 19 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/0
4 root RT 0 0 0 0 S 0.0 0.0 0:00.00 watchdog/0
5 root RT 0 0 0 0 S 0.0 0.0 0:00.50 migration/1
6 root 34 19 0 0 0 S 0.0 0.0 0:00.00 ksoftirqd/1
7 root RT 0 0 0 0 S 0.0 0.0 0:00.00 watchdog/1
8 root 10 -5 0 0 0 S 0.0 0.0 0:00.01 events/0
9 root 10 -5 0 0 0 S 0.0 0.0 0:00.00 events/1
Posted:
Wed Sep 20, 2006 2:16 pm
by enjay
This is what my dial string looks like:
- Code: Select all
exten => _1NXXNXXXXXX,1,AGI(call_log.agi,${EXTEN})
exten => _1NXXNXXXXXX,2,Dial(Zap/g4/${EXTEN}||o)
exten => _1NXXNXXXXXX,3,Dial(Zap/g6/${EXTEN}||o)
exten => _1NXXNXXXXXX,4,Hangup
Posted:
Wed Sep 20, 2006 2:56 pm
by mflorell
Wow, and that's the only thing that changed?
I guess I should try to streamline that script somehow, but I have not seen that kind of load on my servers.
What is the load on your database server?
Do you ever archive or delete records from your call_log table?
How many records are in your call_log table?
Posted:
Wed Sep 20, 2006 3:41 pm
by enjay
Yup thats it as soon as I comment out that line at the begining of the dial string everything works great again system load comes back down to normal etc..
Database Specs
Dual Proc 3.2ghz XEON
4gb RAM
4 15k SCSI RAID5
Database load:
- Code: Select all
13:39:56 up 6 days, 16:11, 2 users, load average: 0.81, 1.01, 0.98
- Code: Select all
mysql> select count(*) from call_log;
+----------+
| count(*) |
+----------+
| 333229 |
+----------+
1 row in set (0.00 sec)
mysql>
I dont do any archiving/deleting..
-enjay
Posted:
Wed Sep 20, 2006 6:35 pm
by mflorell
Wow, that very interesting. Are you using all DBI perl scripts?
How many calls do you place per server every 15 minutes at peak?
(VDAD stats report graph can show you this)
Posted:
Wed Sep 20, 2006 6:37 pm
by enjay
Yea Im using all DBI scripts...
- Code: Select all
GRAPH IN 15 MINUTE INCREMENTS OF TOTAL CALLS PLACED FROM THIS CAMPAIGN
+------+-------------------------------------------------------------------------------------------------------+-------+-------+
| HOUR |0 48 104 168 233 297 361 425 489 553 618 682 746 810| DROPS | TOTAL |
+------+-------------------------------------------------------------------------------------------------------+-------+-------+
|+1600+|>>>>>>>>D*******************************************************X | 57 | 506 |
| 15 |>>>>>>>>>>>>D****************************************************************************************X | 89 | 802 |
+------+-------------------------------------------------------------------------------------------------------+-------+-------+
The drops are high because I was messing with campaign dial level brought it from HARD_LIMIT of a max dial level of 4.5 down to RATIO at 2.5 because of the dropped calls
12 agents.
Posted:
Wed Sep 20, 2006 8:07 pm
by mflorell
That's no more calls than we will do on a single server per 15 minutes(we regularly do over 1000 on a single server for some campaigns). And your hardware is equal to what we use, so I don't know why your loadavg would be skyrocketing.
It can't be a query issue since we have over a million call_log records in our system as any given time. What version of mysqlclientlibs are you using?
As for all of your drops using an ADAPT dial method, we usually set the target difference to a negative number and the dialer will still dial predictively, it just tries to keep an agent waiting for calls. We find this works very well for us while keeping drop rates very low.
Posted:
Wed Sep 20, 2006 10:07 pm
by enjay
I found that lowering my MAX DIAL LEVEL to 2.5 seemed to bring the system to a workable area, and still maintain a ~10 second wait average across the board.
I will test tomarrow to ensure that it continues that way and that the dial level is acceptable and let you know. I also think Im gonna purchase another CPU as the dialers are DL360s (capable of 2 CPU's) that will greatly increase the productivity Im thinking. Not to mention Im going to be adding another 15 agents here shortly.
I think we've beat this one to death bro, and I definately appreciate all your help with it.
I believe my clientlibs are 10-3.23.58-6
-Art
Posted:
Thu Sep 21, 2006 3:57 am
by mflorell
I have been thinking about optimizing the cal_log.agi script since it is called several times per call it should help if it is able to be changed to a FastAGI script or even just streamlined to something less intrusive.
So much to work on so little time
Let me know how moving to dual CPU helps you, I just put a Pentium D CPU in production last night and just received the parts for an Intel Core 2 Duo system yesterday, so I'll post my results about those two as well when I have some good data.
Posted:
Fri Sep 22, 2006 1:01 pm
by enjay
Dude... that CPU made ALL the difference i cant believe how well it works with SMP..
I have 24 agents on this server now dialing at ADAPT_HARD_LIMIT 3.2
my load is under 1.0 full recording everything its screamin!
-enjay
Posted:
Fri Sep 22, 2006 3:48 pm
by mflorell
Cool!
I just posted results of my P4-D test. Dual core makes A LOT of difference:
http://www.eflo.net/VICIDIALforum/viewtopic.php?p=3265