Page 1 of 1

Agents READY but a lot of calls get dropped

PostPosted: Mon Jun 18, 2007 8:12 pm
by ekaftan
I have a problem. I installed a new server (I already have 4) with an independant vicidial instalacion (ie, no shared BD or httpd) and have problems.

One or two agents get in, it works fine.

As soon as 6 or 7 agents log in a lot of calls get dropped before they get transferred. I tried upping the timeout and it makes no difference.

The only difference between this server and the rest, that work fine, is that this one has 2 E1s, one to reach the PSTN and one to reach the agents, who use analog phones connected to an older NEC PBX. I tried defining the extensions as ZAP and as EXTERNAL and the behaviour is the same.

I can't find any clues in the logfiles, except maybe a lot of '2007-06-18 19:13:53|VD_hangup.agi|VD hangup: no VDAC record found:'

Any clues?

thanks.

PostPosted: Tue Jun 19, 2007 6:40 am
by mflorell
turn on logging in the Admin->Servers section of admin.php

You will need to post some agiout.2007-06-XX logfile output of when the calls stop going to agents.

Do you do ntp time syncing on your servers?

PostPosted: Tue Jun 19, 2007 7:58 am
by ekaftan
mflorell wrote:turn on logging in the Admin->Servers section of admin.php

You will need to post some agiout.2007-06-XX logfile output of when the calls stop going to agents.

Do you do ntp time syncing on your servers?


This server is standalone but yes, its ntp synced with pool.ntp.org.

The person administering the machine says that as soon as he modifies something in the campaings every agent gets called. Its the second call to each agent that is not getting through.

Here is some agiout for a dropped call yesterday:


2007-06-18 19:12:30|call_log.agi|Perl Environment Dump:
2007-06-18 19:12:30|call_log.agi|0|8365
2007-06-18 19:12:30|call_log.agi|AGI Environment Dump:
2007-06-18 19:12:30|call_log.agi| -- accountcode =
2007-06-18 19:12:30|call_log.agi| -- callerid = 5978099
2007-06-18 19:12:30|call_log.agi| -- calleridname = V0618191229000067567
2007-06-18 19:12:30|call_log.agi| -- callingani2 = 0
2007-06-18 19:12:30|call_log.agi| -- callingpres = 0
2007-06-18 19:12:30|call_log.agi| -- callingtns = 0
2007-06-18 19:12:30|call_log.agi| -- callington = 0
2007-06-18 19:12:30|call_log.agi| -- channel = Local/95625978000@default-b0b1,1
2007-06-18 19:12:30|call_log.agi| -- context = default
2007-06-18 19:12:30|call_log.agi| -- dnid = unknown
2007-06-18 19:12:30|call_log.agi| -- enhanced = 0.0
2007-06-18 19:12:30|call_log.agi| -- extension = 8365
2007-06-18 19:12:30|call_log.agi| -- language = en
2007-06-18 19:12:30|call_log.agi| -- priority = 1
2007-06-18 19:12:30|call_log.agi| -- rdnis = unknown
2007-06-18 19:12:30|call_log.agi| -- request = call_log.agi
2007-06-18 19:12:30|call_log.agi| -- type = Local
2007-06-18 19:12:30|call_log.agi| -- uniqueid = 1182208349.44
2007-06-18 19:12:30|call_log.agi|AGI Variables: |1182208349.44|Local/95625978000
@default-b0b1,1|8365|Local|V0618191229000067567|
2007-06-18 19:12:30|call_log.agi|+++++ CALL LOG START : 2007-06-18 19:12:30
2007-06-18 19:12:30|call_log.agi||INSERT INTO call_log (uniqueid,channel,channel
_group,type,server_ip,extension,number_dialed,start_time,start_epoch,end_time,en
d_epoch,length_in_sec,length_in_min,caller_code) values('1182208349.44','Local/9
5625978000@default-b0b1,1','','Local','200.9.185.45','8365','','2007-06-18 19:12
:30','1182208350','','','','','V0618191229000067567')|

2007-06-18 19:12:30|agi-VDADtransfer.agi|Perl Environment Dump:
2007-06-18 19:12:30|agi-VDADtransfer.agi|0|8365
2007-06-18 19:12:30|agi-VDADtransfer.agi|callerID changed: V0618191229000067567
2007-06-18 19:12:30|agi-VDADtransfer.agi|AGI Environment Dump:
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- accountcode =
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- callerid = 5978099
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- calleridname = V0618191229000067567
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- callingani2 = 0
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- callingpres = 0
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- callingtns = 0
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- callington = 0
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- channel = Zap/3-1
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- context = default
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- dnid = unknown
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- enhanced = 0.0
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- extension = 8365
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- language = en
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- priority = 2
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- rdnis = unknown
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- request = agi-VDADtransfer.agi
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- type = Zap
2007-06-18 19:12:30|agi-VDADtransfer.agi| -- uniqueid = 1182208349.44
2007-06-18 19:12:30|agi-VDADtransfer.agi|AGI Variables: |1182208349.44|Zap/3-1|8
365|Zap|V0618191229000067567|V0618191229000067567|2|
2007-06-18 19:12:30|agi-VDADtransfer.agi|+++++ VDAD START : |67567|2007-06-18 19
:12:30|1.2.12.1|2|
2007-06-18 19:12:30|agi-VDADtransfer.agi|-- VDAD : |1|update of vac table: V0
618191229000067567
|UPDATE vicidial_auto_calls set uniqueid='1182208349.44', channel='Zap/3-1',stat
us='LIVE' where callerid='V0618191229000067567' order by call_time desc limit 1;
|
2007-06-18 19:12:30|agi-VDADtransfer.agi||INSERT INTO vicidial_log (uniqueid,lea
d_id,campaign_id,call_date,start_epoch,status,phone_code,phone_number,user,proce
ssed) values('1182208349.44','67567','SNWCPTO','2007-06-18 19:12:30','1182208350
','QUEUE','888','5625978000','VDAD','N')|
2007-06-18 19:12:30|agi-VDADtransfer.agi|-- VDAD : |67567|67567|insert to vic
idial_log: 1182208349.44
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi||SELECT count(*) FROM vicidial_auto_cal
ls where status = 'LIVE' and server_ip='200.9.185.45' and campaign_id = 'SNWCPTO
' and call_time < "2007-06-18 19:12:29" and lead_id != '67567';|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:30|agi-VDADtransfer.agi|WWWWWWWW VDAD XFER WAIT: |1|SNWCPTO|Zap
/3-1|V0618191229000067567|1182208349.44|
2007-06-18 19:12:36|agi-VDADtransfer.agi|exiting the VDAD app, transferring call
to 8307
2007-06-18 19:12:36|agi-VDADtransfer.agi|-- VDAD vac record deleted: |1|SNWCP
TO|
2007-06-18 19:12:36|agi-VDADtransfer.agi||UPDATE vicidial_log set status='DROP',
end_epoch='1182208356',length_in_sec='5' where uniqueid = '1182208349.44';|
2007-06-18 19:12:36|agi-VDADtransfer.agi|-- VDAD vicidial_log update: |1|1182
208349.44
2007-06-18 19:12:36|agi-VDADtransfer.agi||UPDATE vicidial_list set status='DROP'
where lead_id = '67567';|
2007-06-18 19:12:36|agi-VDADtransfer.agi|-- VDAD vicidial_list update: |1|675
67

PostPosted: Tue Jun 19, 2007 2:22 pm
by mflorell
Can you post the contents of the vicidial_auto_calls and vicidial_live_agents tables when this happens?

PostPosted: Wed Jun 20, 2007 4:12 pm
by ekaftan
mflorell wrote:Can you post the contents of the vicidial_auto_calls and vicidial_live_agents tables when this happens?


Here is an example. One call was stuck.

mysql> select * from vicidial_auto_calls;
+--------------+--------------+-------------+--------+---------+--------------------+----------------------+---------+------------+--------------+---------------------+-----------+
| auto_call_id | server_ip | campaign_id | status | lead_id | uniqueid | callerid | channel | phone_code | phone_number | call_time | call_type |
+--------------+--------------+-------------+--------+---------+--------------------+----------------------+---------+------------+--------------+---------------------+-----------+
| 2594701 | 200.9.185.45 | WCFCPRE2 | XFER | 60625 | 1182373830.3565099 | V0620171030000060625 | Zap/6-1 | 888 | 5622707328 | 2007-06-20 17:10:30 | OUT |
| 2594709 | 200.9.185.45 | WCFCPRE2 | LIVE | 60639 | 1182373861.3568201 | V0620171101000060639 | Zap/3-1 | 888 | 5622626766 | 2007-06-20 17:11:01 | OUT |
| 2594700 | 200.9.185.45 | WCFCPRE2 | XFER | 60623 | 1182373825.3564701 | V0620171025000060623 | Zap/1-1 | 888 | 5626894354 | 2007-06-20 17:10:25 | OUT |
| 2594706 | 200.9.185.45 | WCFCPRE2 | XFER | 60634 | 1182373848.3566799 | V0620171048000060634 | Zap/7-1 | 888 | 5626034943 | 2007-06-20 17:10:48 | OUT |
| 2594707 | 200.9.185.45 | WCFCPRE2 | LIVE | 60636 | 1182373856.3567500 | V0620171056000060636 | Zap/8-1 | 888 | 5622383232 | 2007-06-20 17:10:56 | OUT |
| 2594705 | 200.9.185.45 | WCFCPRE2 | XFER | 60632 | 1182373848.3566599 | V0620171048000060632 | Zap/2-1 | 888 | 5645348362 | 2007-06-20 17:10:48 | OUT |
| 2594703 | 200.9.185.45 | WCFCPRE2 | XFER | 60629 | 1182373840.3565800 | V0620171040000060629 | Zap/4-1 | 888 | 5655341238 | 2007-06-20 17:10:40 | OUT |
| 2594712 | 200.9.185.45 | WCFCPRE2 | SENT | 60644 | NULL | V0620171121000060644 | NULL | 888 | 56322340579 | 2007-06-20 17:11:21 | OUT |
+--------------+--------------+-------------+--------+---------+--------------------+----------------------+---------+------------+--------------+---------------------+-----------+
8 rows in set (0.00 sec)

mysql> select * from vicidial_live_agents;
+---------------+------+--------------+------------+--------------------+--------+---------+-------------+--------------------+----------------------+---------+-----------+---------------------+---------------------+---------------------+------------------+----------------+------------+
| live_agent_id | user | server_ip | conf_exten | extension | status | lead_id | campaign_id | uniqueid | callerid | channel | random_id | last_call_time | last_update_time | last_call_finish | closer_campaigns | call_server_ip | user_level |
+---------------+------+--------------+------------+--------------------+--------+---------+-------------+--------------------+----------------------+---------+-----------+---------------------+---------------------+---------------------+------------------+----------------+------------+
| 193 | 4730 | 200.9.185.45 | 8600051 | Local/4999@default | PAUSED | 0 | WCFCPRE2 | 0.0000000 | | | 18021304 | 2007-06-20 13:33:09 | 2007-06-20 13:33:27 | 2007-06-20 13:33:09 | | NULL | 1 |
| 195 | 4729 | 200.9.185.45 | 8600052 | Local/4729@default | INCALL | 60623 | WCFCPRE2 | 1182373825.3564701 | V0620171025000060623 | Zap/1-1 | 15143561 | 2007-06-20 17:10:39 | 2007-06-20 17:11:23 | 2007-06-20 17:08:19 | | | 1 |
| 196 | 4724 | 200.9.185.45 | 8600053 | Local/4724@default | INCALL | 60629 | WCFCPRE2 | 1182373840.3565800 | V0620171040000060629 | Zap/4-1 | 18916875 | 2007-06-20 17:10:47 | 2007-06-20 17:11:22 | 2007-06-20 17:08:34 | | | 1 |
| 197 | 4725 | 200.9.185.45 | 8600054 | Local/4725@default | INCALL | 60625 | WCFCPRE2 | 1182373830.3565099 | V0620171030000060625 | Zap/6-1 | 13808621 | 2007-06-20 17:10:38 | 2007-06-20 17:11:23 | 2007-06-20 17:08:12 | | | 1 |
| 198 | 4726 | 200.9.185.45 | 8600055 | Local/4726@default | READY | 0 | WCFCPRE2 | 0.0000000 | | | 11507811 | 2007-06-20 17:09:25 | 2007-06-20 17:11:23 | 2007-06-20 17:10:51 | | | 1 |
| 199 | 4727 | 200.9.185.45 | 8600056 | Local/4727@default | INCALL | 60632 | WCFCPRE2 | 1182373848.3566599 | V0620171048000060632 | Zap/2-1 | 11311046 | 2007-06-20 17:10:56 | 2007-06-20 17:11:23 | 2007-06-20 17:10:35 | | | 1 |
| 200 | 4720 | 200.9.185.45 | 8600057 | Local/4720@default | INCALL | 60634 | WCFCPRE2 | 1182373848.3566799 | V0620171048000060634 | Zap/7-1 | 13527378 | 2007-06-20 17:10:55 | 2007-06-20 17:11:22 | 2007-06-20 17:09:15 | | | 1 |
| 201 | 4728 | 200.9.185.45 | 8600058 | Local/4728@default | INCALL | 60636 | WCFCPRE2 | 1182373856.3567500 | V0620171056000060636 | Zap/8-1 | 14333454 | 2007-06-20 17:11:02 | 2007-06-20 17:11:23 | 2007-06-20 17:10:48 | | | 1 |
| 202 | 4721 | 200.9.185.45 | 8600059 | Local/4721@default | READY | 0 | WCFCPRE2 | 0.0000000 | | | 16794932 | 2007-06-20 17:09:22 | 2007-06-20 17:11:22 | 2007-06-20 17:10:51 | | | 1 |
+---------------+------+--------------+------------+--------------------+--------+---------+-------------+--------------------+----------------------+---------+-----------+---------------------+---------------------+---------------------+------------------+----------------+------------+
9 rows in set (0.00 sec)

PostPosted: Wed Jun 20, 2007 9:42 pm
by mflorell
Are you doing test calls to the local switch?

Everything except for that looks fine.

PostPosted: Wed Jun 20, 2007 9:51 pm
by ekaftan
mflorell wrote:Are you doing test calls to the local switch?

Everything except for that looks fine.


I dont know that do you mean by test calls, but this are all real live calls.

The only difference of this setup is that agents are in analog phones off an old NEC pabx connected to asterisk via a second E1 line, so both the outgoing lines and the agents a Zap trunks.

I tried hiding that to vicidial configuring the agents as EXTERNAL and also tried defining them as ZAP extensions and the result is the same.

thanks.

PostPosted: Thu Jun 21, 2007 1:35 pm
by mflorell
I haven't done a setup like that before. It might be causing problems because you have agents and calls going out over the same channels.

PostPosted: Fri Jun 22, 2007 1:24 pm
by ekaftan
mflorell wrote:I haven't done a setup like that before. It might be causing problems because you have agents and calls going out over the same channels.


I can code in perl (intermediate level). Can you point me to where to look and how to work with you to fix it?

I would be pleased to return the code to vicidial and enable that setup as supported.

Thanks.

PostPosted: Fri Jun 22, 2007 3:05 pm
by mflorell
I'm not really sure how it would work actually. I've never even thought of it. Have you tried using VOIP just to make sure that your system works properly?

PostPosted: Fri Jun 22, 2007 3:22 pm
by ekaftan
mflorell wrote:I'm not really sure how it would work actually. I've never even thought of it. Have you tried using VOIP just to make sure that your system works properly?


I haven't been able to give it a lot of load using SIP extensions, but it does work with two or three agents.

Whats the algorithm used to select an agent? maybe all thats happening is that the SELECT used to hit the db is not getting any results back because it filters out all the ZAP lines.

Although, the reports from the admin ofthe server say that all agents get one call, then no more call for a while, then another call, so I would bet its more a problem of how the agents get marked back READY after one call.

They show up as READY on the monitor, but VDAD-transfer does not select them.

PostPosted: Sat Jun 23, 2007 7:33 am
by mflorell
What version of astguiclient are you using?

PostPosted: Sat Jun 23, 2007 9:16 am
by ekaftan
mflorell wrote:What version of astguiclient are you using?


Vicidial says: VERSION: 2.0.65 BUILD: 60828-1115
astguiclient: VERSION: 2.0.1 BUILD: 60815-1016

(should't they be the same?)

PostPosted: Sat Jun 23, 2007 9:29 am
by ekaftan
ekaftan wrote:
mflorell wrote:What version of astguiclient are you using?


Vicidial says: VERSION: 2.0.65 BUILD: 60828-1115
astguiclient: VERSION: 2.0.1 BUILD: 60815-1016

(should't they be the same?)


I am upgrading to 2.0.3. I will retest and report...

PostPosted: Fri Jul 06, 2007 11:17 pm
by ekaftan
ekaftan wrote:
ekaftan wrote:
mflorell wrote:What version of astguiclient are you using?


Vicidial says: VERSION: 2.0.65 BUILD: 60828-1115
astguiclient: VERSION: 2.0.1 BUILD: 60815-1016

(should't they be the same?)


I am upgrading to 2.0.3. I will retest and report...


I upgraded to 2.0.3 and now transfer works ok.

I now have another problem, but will start a new thread for that.