vicidial.org

by **PierreDeux** » Wed Nov 13, 2013 11:28 am

Vicibox 5.0.3, admin.php VERSION: 2.8-417a BUILD: 131019-0849
6 dialer servers, 1 web & 1 db server.

Something weird is going on with my agent wait time logging. It's even bigger, than total agent logged in time. Here is the example:

Code: Select all: TOTAL CALLS TAKEN: 158 [DOWNLOAD] TALK TIME: 31:46 AVERAGE: 0:12 PAUSE TIME: 9:23 AVERAGE: 0:04 WAIT TIME: 5:06:17 AVERAGE: 1:56 WRAPUP TIME: 50:03 AVERAGE: 0:19 ---------------------------------------------------------------- TOTAL ACTIVE AGENT TIME: 6:37:29 FIRST LOGIN: 2013-11-13 09:52:26 LAST LOG ACTIVITY: 2013-11-13 11:18:30 ----------------------------------------- TOTAL LOGGED-IN TIME: 1:26:04

Seems it started after I upgraded from 2.4 to 2.8. However it was more a fresh install, than an update: I've installed completely new vicibox 5.0.3. servers, the only "old" thing I have is the database, however it was properly updated with a set uf .sql files and has the latest schema version.

by **DomeDan** » Thu Nov 14, 2013 10:43 am

properly updated with a set of .sql

Tell us in detail what you did and what sql schema you got now

what report did you take the data from?
and post the whole link with the GET-data for the report you run like this:
AST_agent_performance_detail.php?DB=&query_date=2013-11-14&end_date=2013-11-14&group%5B%5D=--ALL--

by **PierreDeux** » Thu Nov 14, 2013 12:53 pm

DomeDan wrote:
properly updated with a set of .sql

Tell us in detail what you did and what sql schema you got now

Is there any other way to apply .sql files to existing db? Current revision is 1359

DomeDan wrote:what report did you take the data from?

AST_agent_time_sheet.php?calls_summary=1&agent=#USERNAME_HERE&query_date=2013-11-14

DomeDan wrote:and post the whole link with the GET-data for the report you run like this:
AST_agent_performance_detail.php?DB=&query_date=2013-11-14&end_date=2013-11-14&group%5B%5D=--ALL--

Too much output there considering I have 130-140 agents per shift + a lot of things to blur (agent names etc). However wait time is also crazy, actually I found the issue when checked this report.

Today I've noticed that the issue is not affecting all agents, only some of them. 2 agents from one user group with the same settings, using softphone accounts on the same asterisk server: one of them has the issue, another - not. That's at even more weird, as I can't find any difference between them, except username and password.

by **williamconley** » Thu Nov 14, 2013 8:59 pm

1) If you upgraded your db and now have this "problem", you may have upgraded your db incorrectly. HOW (precisely, get your cli history!) did you upgrade your DB?
2) Just because it comes up every day, what version of asterisk is listed under admin->servers for each server?
3) /vicidial/admin.php?ADD=999991 -> do all revisions and times match?
4) Modify the url to have "&DB=1" and try to run the query that gathers the wait time. Look for one or two entries that are "outrageous". Sometimes time is "off" slightly and causes a huge number because it's actually negative 1 (which is impossible) and the result is that the variable ends up with the largest number possible for that variable type (minus 1). IE: A huge number. This can happen if time or time zone is out of sync between php and/or db and/or different servers.

by **DomeDan** » Fri Nov 15, 2013 4:09 am

Things I come to think of:
* if you use letters in the agent id then make sure you dont mix upper and lower case anywhere,
if agents login with different upper/lower mix that will cause problems, but its usually resulting in NULL values in reports
* you dont need to test "&DB=1" on AST_agent_time_sheet.php because it currently does not check that GET value
* When you say it only happens to two agents then I guess they use the back button in the browser or similar bad behavior.
* is there anything else the users have in common, maybe it only happens on one of the asterisk servers? etc
* does everything run the same version, Admin page / Agent page / scripts ?

post the data from the mysql table: vicidial_agent_log, use this query to view only the important stuff and you dont need to blur any of the output:

Code: Select all: SELECT agent_log_id, event_time, wait_epoch, wait_sec, status FROM vicidial_agent_log WHERE DATE(event_time)='2013-11-15' and user='1234'

Take a date and user you know has the problem

found a related topic: viewtopic.php?p=62409 does not tell you much though

by **PierreDeux** » Fri Nov 15, 2013 5:58 am

williamconley wrote:1) If you upgraded your db and now have this "problem", you may have upgraded your db incorrectly. HOW (precisely, get your cli history!) did you upgrade your DB?

I will not give you that exact comand since it was almost 2 weeks ago, however here is the same one:

Code: Select all: mysql -f -u root -p$PASSWD asterisk < upgrade_patch_name(2.4,2.6,2.8).sql

2) Just because it comes up every day, what version of asterisk is listed under admin->servers for each server?

All the same - 1.8.23.0-vici

3) /vicidial/admin.php?ADD=999991 -> do all revisions and times match?

Yes, 2040 everywhere.

4) Modify the url to have "&DB=1" and try to run the query that gathers the wait time. Look for one or two entries that are "outrageous". Sometimes time is "off" slightly and causes a huge number because it's actually negative 1 (which is impossible) and the result is that the variable ends up with the largest number possible for that variable type (minus 1). IE: A huge number.

what page url?

This can happen if time or time zone is out of sync between php and/or db and/or different servers.

This was the first I've checked - everything is synced.

by **PierreDeux** » Fri Nov 15, 2013 6:07 am

DomeDan wrote:Things I come to think of:
* if you use letters in the agent id then make sure you dont mix upper and lower case anywhere,
if agents login with different upper/lower mix that will cause problems, but its usually resulting in NULL values in reports

I don't mix them in usernames, in addition the same usernames had no problems before update.

* you dont need to test "&DB=1" on AST_agent_time_sheet.php because it currently does not check that GET value

* When you say it only happens to two agents then I guess they use the back button in the browser or similar bad behavior.

No, it happens to much more agents, than 2. I just mean that some agents on the same server have those problems and some - not. Here is a screenshot showing the problem. The ones having a big >1m avg. wait time have the issue.
http://awesomescreenshot.com/0961yp7od8

* is there anything else the users have in common, maybe it only happens on one of the asterisk servers? etc

I was thinking about that already, but can't find anything, that will be common for those agents with issues

All have the same settings, use different asterisk servers, etc.

* does everything run the same version, Admin page / Agent page / scripts ?

Sure thing.

post the data from the mysql table: vicidial_agent_log, use this query to view only the important stuff and you dont need to blur any of the output:
Code: Select all
SELECT agent_log_id, event_time, wait_epoch, wait_sec, status FROM vicidial_agent_log WHERE DATE(event_time)='2013-11-15' and user='1234'

Take a date and user you know has the problem

Code: Select all: +--------------+---------------------+------------+----------+--------+ | agent_log_id | event_time | wait_epoch | wait_sec | status | +--------------+---------------------+------------+----------+--------+ | 40363031 | 2013-11-15 02:24:39 | 1384500293 | 221 | NI | | 40363044 | 2013-11-15 02:28:59 | 1384500539 | 683 | NI | | 40363088 | 2013-11-15 02:40:28 | 1384501228 | 511 | NI | | 40363173 | 2013-11-15 02:49:05 | 1384501745 | 268 | A | | 40363209 | 2013-11-15 02:53:39 | 1384502019 | 58 | NI | | 40363231 | 2013-11-15 02:55:02 | 1384502102 | 1 | NULL | | 40363233 | 2013-11-15 02:55:03 | 1384502107 | 1326 | A | | 40363248 | 2013-11-15 02:56:05 | 1384502165 | 1 | NULL | | 40363249 | 2013-11-15 02:56:06 | 1384502169 | 392 | A | | 40363263 | 2013-11-15 02:56:47 | 1384502207 | 0 | NULL | | 40363264 | 2013-11-15 02:56:47 | 1384502211 | 58 | A | | 40363274 | 2013-11-15 02:57:09 | 1384502229 | 0 | NULL | | 40363275 | 2013-11-15 02:57:09 | 1384502230 | 16 | NULL | | 40363282 | 2013-11-15 02:57:26 | 1384502250 | 160 | NI | | 40363294 | 2013-11-15 02:58:01 | 1384502281 | 0 | NULL | | 40363295 | 2013-11-15 02:58:01 | 1384502283 | 28 | A | | 40363299 | 2013-11-15 02:58:12 | 1384502292 | 0 | NULL | | 40363300 | 2013-11-15 02:58:12 | 1384502292 | 18 | NULL | | 40363301 | 2013-11-15 02:58:30 | 1384502313 | 163 | NI | | 40363329 | 2013-11-15 02:59:46 | 1384502386 | 0 | NULL | | 40363330 | 2013-11-15 02:59:46 | 1384502390 | 200 | A | | 40363339 | 2013-11-15 03:00:32 | 1384502432 | 0 | NULL | | 40363340 | 2013-11-15 03:00:32 | 1384502432 | 13 | NULL | | 40363341 | 2013-11-15 03:00:45 | 1384502448 | 146 | NI | | 40363355 | 2013-11-15 03:01:30 | 1384502490 | 0 | NULL | | 40363356 | 2013-11-15 03:01:30 | 1384502492 | 405 | NI | | 40363384 | 2013-11-15 03:02:53 | 1384502574 | 0 | NULL | | 40363385 | 2013-11-15 03:02:54 | 1384502577 | 45 | A | | 40363395 | 2013-11-15 03:03:12 | 1384502592 | 0 | NULL | | 40363396 | 2013-11-15 03:03:12 | 1384502596 | 120 | A | | 40363411 | 2013-11-15 03:03:44 | 1384502624 | 0 | NULL | | 40363412 | 2013-11-15 03:03:44 | 1384502627 | 28 | A | | 40363427 | 2013-11-15 03:04:14 | 1384502654 | 0 | NULL | | 40363428 | 2013-11-15 03:04:14 | 1384502657 | 28 | A | | 40363452 | 2013-11-15 03:04:46 | 1384502686 | 1 | NI | | 40363453 | 2013-11-15 03:04:46 | 1384502686 | 0 | NULL | | 40363462 | 2013-11-15 03:04:54 | 1384502694 | 6 | A | | 40363473 | 2013-11-15 03:05:07 | 1384502707 | 3 | A | | 40363481 | 2013-11-15 03:05:16 | 1384502716 | 1 | A | | 40363494 | 2013-11-15 03:05:40 | 1384502745 | 130 | A | | 40363516 | 2013-11-15 03:06:09 | 1384502769 | 0 | NULL | | 40363518 | 2013-11-15 03:06:09 | 1384502773 | 131 | NI | | 40363535 | 2013-11-15 03:06:42 | 1384502802 | 0 | NULL | | 40363536 | 2013-11-15 03:06:42 | 1384502805 | 31 | NI | | 40363559 | 2013-11-15 03:07:53 | 1384502873 | 0 | NULL | | 40363560 | 2013-11-15 03:07:53 | 1384502876 | 271 | NI | | 40363580 | 2013-11-15 03:08:53 | 1384502933 | 1 | NULL | | 40363581 | 2013-11-15 03:08:54 | 1384502995 | 352 | NULL | | 40363600 | 2013-11-15 03:09:55 | 1384502995 | 0 | NULL | | 40363601 | 2013-11-15 03:09:55 | 1384502995 | 3 | NI | | 40363613 | 2013-11-15 03:10:20 | 1384503020 | 4 | NULL | | 40363616 | 2013-11-15 03:10:24 | 1384503028 | 28 | A | | 40363629 | 2013-11-15 03:10:50 | 1384503050 | 0 | NULL | | 40363630 | 2013-11-15 03:10:50 | 1384503068 | 6 | CALLBK | | 40363637 | 2013-11-15 03:11:08 | 1384503068 | 0 | NULL | | 40363638 | 2013-11-15 03:11:08 | 1384503068 | 17 | NULL | | 40363643 | 2013-11-15 03:11:25 | 1384503092 | 244 | CALLBK | | 40363712 | 2013-11-15 03:13:57 | 1384503237 | 0 | NULL | | 40363713 | 2013-11-15 03:13:57 | 1384503237 | 50 | A | | 40363733 | 2013-11-15 03:14:53 | 1384503293 | 15 | A | | 40363744 | 2013-11-15 03:15:12 | 1384503312 | 12 | A | | 40363768 | 2013-11-15 03:16:07 | 1384503367 | 38 | A | | 40363783 | 2013-11-15 03:16:56 | 1384503416 | 38 | A | | 40363806 | 2013-11-15 03:18:05 | 1384503485 | 23 | A | | 40363818 | 2013-11-15 03:18:33 | 1384503513 | 19 | A | | 40363836 | 2013-11-15 03:18:57 | 1384503537 | 9 | A | | 40363839 | 2013-11-15 03:19:16 | 1384503556 | 7 | A | | 40363850 | 2013-11-15 03:19:29 | 1384503569 | 29 | A | | 40363864 | 2013-11-15 03:20:02 | 1384503602 | 18 | A | | 40363876 | 2013-11-15 03:20:24 | 1384503624 | 7 | A | | 40363886 | 2013-11-15 03:20:37 | 1384503637 | 40 | A | | 40363898 | 2013-11-15 03:21:21 | 1384503681 | 16 | A | | 40363909 | 2013-11-15 03:21:43 | 1384503703 | 17 | A | | 40363917 | 2013-11-15 03:22:06 | 1384503726 | 4 | A | | 40363925 | 2013-11-15 03:22:13 | 1384503733 | 4 | A | | 40363928 | 2013-11-15 03:22:21 | 1384503741 | 1 | A | | 40363934 | 2013-11-15 03:22:30 | 1384503750 | 8 | A | | 40363943 | 2013-11-15 03:22:50 | 1384503770 | 5 | A | | 40363948 | 2013-11-15 03:23:01 | 1384503781 | 3 | A | | 40363953 | 2013-11-15 03:23:10 | 1384503790 | 2 | A | | 40363955 | 2013-11-15 03:23:17 | 1384503797 | 7 | NI | | 40363960 | 2013-11-15 03:23:27 | 1384503807 | 9 | NI | | 40363968 | 2013-11-15 03:23:42 | 1384503822 | 9 | A | | 40363975 | 2013-11-15 03:24:00 | 1384503850 | 10 | A | | 40363980 | 2013-11-15 03:24:10 | 1384503850 | 0 | NULL | | 40363981 | 2013-11-15 03:24:09 | 1384503851 | 10 | NULL | | 40363986 | 2013-11-15 03:24:21 | 1384503869 | 2 | A | | 40363988 | 2013-11-15 03:24:29 | 1384503869 | 0 | NULL | | 40363989 | 2013-11-15 03:24:29 | 1384503869 | 17 | NULL | | 40363993 | 2013-11-15 03:24:46 | 1384503889 | 113 | NI | | 40364004 | 2013-11-15 03:25:23 | 1384503923 | 0 | NULL | | 40364005 | 2013-11-15 03:25:23 | 1384503926 | 241 | NI | | 40364014 | 2013-11-15 03:26:16 | 1384503976 | 0 | NULL | | 40364015 | 2013-11-15 03:26:16 | 1384503979 | 27 | NI | | 40364017 | 2013-11-15 03:26:29 | 1384503990 | 0 | NULL | | 40364018 | 2013-11-15 03:26:30 | 1384503993 | 528 | A | | 40364024 | 2013-11-15 03:27:11 | 1384504031 | 0 | NULL | | 40364025 | 2013-11-15 03:27:11 | 1384504031 | 37 | A | | 40364036 | 2013-11-15 03:27:56 | 1384504076 | 10 | NULL | | 40364041 | 2013-11-15 03:28:06 | 1384504089 | 152 | NI | | 40364049 | 2013-11-15 03:28:34 | 1384504114 | 0 | NULL | | 40364050 | 2013-11-15 03:28:34 | 1384504114 | 33 | A | | 40364061 | 2013-11-15 03:29:13 | 1384504153 | 4 | NULL | | 40364062 | 2013-11-15 03:29:17 | 1384504161 | 211 | NI | | 40364072 | 2013-11-15 03:30:01 | 1384504201 | 0 | NULL | | 40364073 | 2013-11-15 03:30:01 | 1384504214 | 31 | NI | | 40364084 | 2013-11-15 03:30:14 | 1384504214 | 0 | NULL | | 40364085 | 2013-11-15 03:30:14 | 1384504214 | 8 | A | | 40364092 | 2013-11-15 03:30:28 | 1384504228 | 30 | A | | 40364105 | 2013-11-15 03:31:03 | 1384504263 | 35 | NULL | | 40364116 | 2013-11-15 03:31:38 | 1384504301 | 449 | A | | 40364129 | 2013-11-15 03:32:21 | 1384504341 | 0 | NULL | | 40364130 | 2013-11-15 03:32:21 | 1384504345 | 42 | A | | 40364133 | 2013-11-15 03:32:36 | 1384504356 | 0 | NULL | | 40364134 | 2013-11-15 03:32:36 | 1384504359 | 806 | A | | 40364158 | 2013-11-15 03:33:27 | 1384504407 | 0 | NULL | | 40364159 | 2013-11-15 03:33:27 | 1384504410 | 430 | NI | | 40364224 | 2013-11-15 03:34:56 | 1384504496 | 0 | NULL | | 40364225 | 2013-11-15 03:34:56 | 1384504500 | 238 | NI | | 40364248 | 2013-11-15 03:36:06 | 1384504566 | 0 | NULL | | 40364249 | 2013-11-15 03:36:06 | 1384504567 | 11 | NI | | 40364258 | 2013-11-15 03:36:30 | 1384504590 | 10 | NULL | | 40364261 | 2013-11-15 03:36:40 | 1384504631 | 314 | A | | 40364275 | 2013-11-15 03:37:11 | 1384504631 | 0 | NULL | | 40364276 | 2013-11-15 03:37:11 | 1384504631 | 13 | NULL | | 40364279 | 2013-11-15 03:37:24 | 1384504648 | 21 | A | | 40364306 | 2013-11-15 03:38:12 | 1384504692 | 0 | NULL | | 40364307 | 2013-11-15 03:38:12 | 1384504695 | 55 | A | | 40364321 | 2013-11-15 03:38:35 | 1384504715 | 0 | NULL | | 40364322 | 2013-11-15 03:38:35 | 1384504718 | 119 | A | | 40364343 | 2013-11-15 03:39:29 | 1384504769 | 1 | NULL | | 40364344 | 2013-11-15 03:39:30 | 1384504772 | 1083 | A | | 40364368 | 2013-11-15 03:40:23 | 1384504823 | 0 | NULL | | 40364369 | 2013-11-15 03:40:23 | 1384504823 | 10 | A | | 40364382 | 2013-11-15 03:40:54 | 1384504854 | 23 | A | | 40364389 | 2013-11-15 03:41:23 | 1384504883 | 15 | A | | 40364393 | 2013-11-15 03:41:41 | 1384504901 | 43 | A | | 40364412 | 2013-11-15 03:42:31 | 1384504951 | 19 | NI | | 40364426 | 2013-11-15 03:43:15 | 1384504998 | 24 | A | | 40364435 | 2013-11-15 03:43:26 | 1384505006 | 0 | NULL | | 40364436 | 2013-11-15 03:43:26 | 1384505009 | 1199 | A | | 40364449 | 2013-11-15 03:44:22 | 1384505062 | 0 | NULL | | 40364450 | 2013-11-15 03:44:22 | 1384505062 | 17 | A | | 40364460 | 2013-11-15 03:44:45 | 1384505085 | 8 | A | | 40364467 | 2013-11-15 03:44:57 | 1384505097 | 13 | A | | 40364473 | 2013-11-15 03:45:13 | 1384505113 | 15 | A | | 40364483 | 2013-11-15 03:45:38 | 1384505138 | 15 | A | | 40364489 | 2013-11-15 03:46:03 | 1384505165 | 447 | NI | | 40364521 | 2013-11-15 03:47:26 | 1384505246 | 0 | NULL | | 40364522 | 2013-11-15 03:47:26 | 1384505246 | 8 | NULL | | 40364525 | 2013-11-15 03:47:34 | 1384505258 | 164 | A | | 40364539 | 2013-11-15 03:48:01 | 1384505281 | 0 | NULL | | 40364540 | 2013-11-15 03:48:01 | 1384505281 | 8 | A | | 40364545 | 2013-11-15 03:48:14 | 1384505294 | 18 | NI | | 40364551 | 2013-11-15 03:48:37 | 1384505317 | 19 | A | | 40364566 | 2013-11-15 03:49:04 | 1384505344 | 19 | A | | 40364574 | 2013-11-15 03:49:27 | 1384505367 | 12 | A | | 40364580 | 2013-11-15 03:49:44 | 1384505384 | 5 | A | | 40364586 | 2013-11-15 03:49:55 | 1384505395 | 18 | A | | 40364595 | 2013-11-15 03:50:17 | 1384505417 | 9 | A | | 40364601 | 2013-11-15 03:50:34 | 1384505434 | 36 | A | | 40364614 | 2013-11-15 03:51:18 | 1384505478 | 60 | NI | | 40364626 | 2013-11-15 03:52:24 | 1384505544 | 53 | A | | 40364643 | 2013-11-15 03:53:21 | 1384505601 | 11 | A | | 40364649 | 2013-11-15 03:53:40 | 1384505620 | 6 | A | | 40364653 | 2013-11-15 03:53:51 | 1384505631 | 1 | A | | 40364656 | 2013-11-15 03:53:56 | 1384505636 | 11 | A | | 40364663 | 2013-11-15 03:54:11 | 1384505651 | 16 | A | | 40364672 | 2013-11-15 03:54:31 | 1384505671 | 63 | NI | | 40364690 | 2013-11-15 03:55:44 | 1384505744 | 49 | A | | 40364700 | 2013-11-15 03:56:44 | 1384505804 | 11 | A | | 40364706 | 2013-11-15 03:57:01 | 1384505821 | 17 | A | | 40364719 | 2013-11-15 03:57:27 | 1384505847 | 10 | A | | 40364737 | 2013-11-15 03:58:00 | 1384505880 | 18 | A | | 40364746 | 2013-11-15 03:58:31 | 1384505911 | 4 | A | | 40364750 | 2013-11-15 03:58:39 | 1384505919 | 12 | A | | 40364757 | 2013-11-15 03:58:58 | 1384505938 | 8 | A | | 40364767 | 2013-11-15 03:59:09 | 1384505949 | 6 | NI | | 40364774 | 2013-11-15 03:59:24 | 1384505964 | 2 | NULL | | 40364776 | 2013-11-15 03:59:26 | 1384505967 | 0 | NULL | | 40364801 | 2013-11-15 04:10:21 | 1384506634 | 26 | NULL | | 40364810 | 2013-11-15 04:11:00 | 1384506664 | 50 | A | | 40364816 | 2013-11-15 04:11:33 | 1384506693 | 0 | NULL | | 40364817 | 2013-11-15 04:11:33 | 1384506696 | 72 | CALLBK | | 40364838 | 2013-11-15 04:12:40 | 1384506760 | 0 | NULL | | 40364839 | 2013-11-15 04:12:40 | 1384506760 | 10 | NULL | | 40364840 | 2013-11-15 04:12:50 | 1384506773 | 337 | A | | 40364848 | 2013-11-15 04:13:38 | 1384506818 | 1 | NULL | | 40364849 | 2013-11-15 04:13:39 | 1384506821 | 77 | A | | 40364857 | 2013-11-15 04:13:57 | 1384506837 | 0 | NULL | | 40364858 | 2013-11-15 04:13:57 | 1384506837 | 12 | NULL | | 40364863 | 2013-11-15 04:14:09 | 1384506853 | 358 | A | | 40364875 | 2013-11-15 04:14:45 | 1384506885 | 0 | NULL | | 40364876 | 2013-11-15 04:14:45 | 1384506888 | 135 | A | | 40364900 | 2013-11-15 04:15:44 | 1384506944 | 0 | NULL | | 40364901 | 2013-11-15 04:15:44 | 1384506948 | 45 | A | | 40364909 | 2013-11-15 04:16:10 | 1384506970 | 0 | NULL | | 40364910 | 2013-11-15 04:16:10 | 1384506973 | 135 | A | | 40364919 | 2013-11-15 04:16:38 | 1384506998 | 0 | NULL | | 40364920 | 2013-11-15 04:16:38 | 1384506998 | 19 | NULL | | 40364926 | 2013-11-15 04:16:57 | 1384507020 | 6 | A | | 40364934 | 2013-11-15 04:17:17 | 1384507037 | 0 | NULL | | 40364935 | 2013-11-15 04:17:17 | 1384507037 | 23 | A | | 40364943 | 2013-11-15 04:17:45 | 1384507065 | 8 | A | | 40364955 | 2013-11-15 04:18:12 | 1384507095 | 38 | A | | 40364958 | 2013-11-15 04:18:42 | 1384507122 | 0 | NULL | | 40364959 | 2013-11-15 04:18:42 | 1384507126 | 195 | NI | | 40364968 | 2013-11-15 04:19:30 | 1384507170 | 0 | NULL | | 40364969 | 2013-11-15 04:19:30 | 1384507173 | 593 | A | | 40364986 | 2013-11-15 04:20:18 | 1384507218 | 0 | NULL | | 40364987 | 2013-11-15 04:20:18 | 1384507221 | 78 | A | | 40364990 | 2013-11-15 04:20:39 | 1384507239 | 0 | NULL | | 40364991 | 2013-11-15 04:20:39 | 1384507242 | 779 | A | | 40365003 | 2013-11-15 04:21:23 | 1384507283 | 1 | NULL | | 40365004 | 2013-11-15 04:21:24 | 1384507286 | 468 | NI | | 40365015 | 2013-11-15 04:21:59 | 1384507319 | 0 | NULL | | 40365016 | 2013-11-15 04:21:59 | 1384507336 | 60 | A | | 40365023 | 2013-11-15 04:22:16 | 1384507336 | 0 | NULL | | 40365024 | 2013-11-15 04:22:16 | 1384507336 | 7 | NULL | | 40365025 | 2013-11-15 04:22:23 | 1384507345 | 28 | A | | 40365045 | 2013-11-15 04:23:57 | 1384507437 | 1 | NULL | | 40365046 | 2013-11-15 04:23:58 | 1384507440 | 291 | NI | | 40365089 | 2013-11-15 04:25:07 | 1384507507 | 1 | NULL | | 40365092 | 2013-11-15 04:25:08 | 1384507511 | 23 | NI | | 40365113 | 2013-11-15 04:25:59 | 1384507559 | 0 | NULL | | 40365114 | 2013-11-15 04:25:59 | 1384507562 | 573 | NI | | 40365126 | 2013-11-15 04:26:49 | 1384507609 | 0 | NULL | | 40365127 | 2013-11-15 04:26:49 | 1384507613 | 1153 | NI | | 40365144 | 2013-11-15 04:27:42 | 1384507662 | 0 | NULL | | 40365145 | 2013-11-15 04:27:42 | 1384507667 | 1065 | NI | | 40365172 | 2013-11-15 04:28:46 | 1384507726 | 0 | NULL | | 40365175 | 2013-11-15 04:28:46 | 1384507729 | 32 | NI | | 40365195 | 2013-11-15 04:29:23 | 1384507763 | 0 | NULL | | 40365196 | 2013-11-15 04:29:23 | 1384507767 | 1386 | A | | 40365218 | 2013-11-15 04:30:27 | 1384507827 | 0 | NULL | | 40365219 | 2013-11-15 04:30:27 | 1384507829 | 210 | A | | 40365234 | 2013-11-15 04:31:03 | 1384507863 | 0 | NULL | | 40365237 | 2013-11-15 04:31:03 | 1384507866 | 324 | A | | 40365248 | 2013-11-15 04:31:46 | 1384507906 | 0 | NULL | | 40365249 | 2013-11-15 04:31:46 | 1384507910 | 45 | A | | 40365252 | 2013-11-15 04:32:03 | 1384507923 | 0 | NULL | | 40365254 | 2013-11-15 04:32:03 | 1384507925 | 15 | NULL | | 40365257 | 2013-11-15 04:32:20 | 1384507944 | 325 | A | | 40365264 | 2013-11-15 04:33:04 | 1384507984 | 0 | NULL | | 40365265 | 2013-11-15 04:33:04 | 1384507987 | 362 | A | | 40365274 | 2013-11-15 04:33:50 | 1384508030 | 0 | NULL | | 40365275 | 2013-11-15 04:33:50 | 1384508033 | 85 | NI | | 40365285 | 2013-11-15 04:34:42 | 1384508082 | 0 | NULL | | 40365286 | 2013-11-15 04:34:42 | 1384508082 | 62 | NULL | | 40365294 | 2013-11-15 04:35:44 | 1384508147 | 324 | NI | | 40365306 | 2013-11-15 04:37:15 | 1384508235 | 0 | NULL | | 40365307 | 2013-11-15 04:37:15 | 1384508239 | 378 | A | | 40365321 | 2013-11-15 04:37:59 | 1384508279 | 0 | NULL | | 40365322 | 2013-11-15 04:37:59 | 1384508283 | 1222 | A | | 40365336 | 2013-11-15 04:38:58 | 1384508338 | 0 | NULL | | 40365337 | 2013-11-15 04:38:58 | 1384508346 | 3 | A | | 40365339 | 2013-11-15 04:39:06 | 1384508346 | 0 | NULL | | 40365340 | 2013-11-15 04:39:06 | 1384508347 | 16 | NULL | | 40365342 | 2013-11-15 04:39:23 | 1384508368 | 154 | A | | 40365349 | 2013-11-15 04:39:51 | 1384508391 | 0 | NULL | | 40365350 | 2013-11-15 04:39:51 | 1384508393 | 69 | NI | | 40365365 | 2013-11-15 04:41:31 | 1384508492 | 0 | NULL | | 40365366 | 2013-11-15 04:41:32 | 1384508492 | 5 | NULL | | 40365370 | 2013-11-15 04:41:37 | 1384508500 | 41 | A | | 40365377 | 2013-11-15 04:42:08 | 1384508528 | 0 | NULL | | 40365378 | 2013-11-15 04:42:08 | 1384508547 | 4 | NULL | | 40365380 | 2013-11-15 04:42:27 | 1384508547 | 0 | NULL | | 40365381 | 2013-11-15 04:42:27 | 1384508547 | 8 | A | | 40365385 | 2013-11-15 04:42:55 | 1384508575 | 24 | NULL | | 40365390 | 2013-11-15 04:43:19 | 1384508602 | 189 | NI | | 40365414 | 2013-11-15 04:44:41 | 1384508681 | 0 | NULL | | 40365415 | 2013-11-15 04:44:41 | 1384508681 | 1 | NI | | 40365422 | 2013-11-15 04:44:54 | 1384508696 | 45 | A | | 40365436 | 2013-11-15 04:45:27 | 1384508727 | 0 | NULL | | 40365437 | 2013-11-15 04:45:27 | 1384508727 | 11 | NULL | | 40365439 | 2013-11-15 04:45:38 | 1384508740 | 2 | NI | | 40365448 | 2013-11-15 04:45:51 | 1384508751 | 6 | NI | | 40365456 | 2013-11-15 04:46:06 | 1384508766 | 7 | A | | 40365465 | 2013-11-15 04:46:20 | 1384508780 | 22 | A | | 40365481 | 2013-11-15 04:46:59 | 1384508819 | 56 | NULL | | 40365497 | 2013-11-15 04:47:55 | 1384508878 | 37 | A | | 40365509 | 2013-11-15 04:48:25 | 1384508905 | 0 | NULL | | 40365510 | 2013-11-15 04:48:25 | 1384508908 | 105 | NI | | 40365526 | 2013-11-15 04:49:08 | 1384508948 | 0 | NULL | | 40365527 | 2013-11-15 04:49:08 | 1384509004 | 619 | NULL | | 40365542 | 2013-11-15 04:50:04 | 1384509004 | 0 | NULL | | 40365544 | 2013-11-15 04:50:04 | 1384509013 | 24 | NI | | 40365547 | 2013-11-15 04:50:13 | 1384509013 | 27 | NULL | | 40365560 | 2013-11-15 04:50:40 | 1384509044 | 516 | A | | 40365573 | 2013-11-15 04:51:30 | 1384509090 | 0 | NULL | | 40365574 | 2013-11-15 04:51:30 | 1384509130 | 642 | A | | 40365585 | 2013-11-15 04:52:10 | 1384509130 | 0 | NULL | | 40365587 | 2013-11-15 04:52:10 | 1384509131 | 7 | NULL | | 40365589 | 2013-11-15 04:52:18 | 1384509154 | 59 | A | | 40365596 | 2013-11-15 04:52:34 | 1384509154 | 0 | NULL | | 40365597 | 2013-11-15 04:52:34 | 1384509154 | 12 | NULL | | 40365604 | 2013-11-15 04:52:46 | 1384509168 | 5 | NULL | | 40365610 | 2013-11-15 04:52:53 | 1384509176 | 15 | A | | 40365612 | 2013-11-15 04:53:08 | 1384509188 | 0 | NULL | | 40365615 | 2013-11-15 04:53:08 | 1384509189 | 38 | NULL | | 40365623 | 2013-11-15 04:53:47 | 1384509231 | 406 | NI | | 40365651 | 2013-11-15 04:54:56 | 1384509296 | 0 | NULL | | 40365653 | 2013-11-15 04:54:56 | 1384509300 | 253 | NI | | 40365665 | 2013-11-15 04:55:36 | 1384509336 | 1 | NULL | | 40365666 | 2013-11-15 04:55:37 | 1384509340 | 636 | A | | 40365685 | 2013-11-15 04:56:22 | 1384509382 | 1 | NULL | | 40365687 | 2013-11-15 04:56:23 | 1384509385 | 2 | A | | 40365704 | 2013-11-15 04:57:09 | 1384509432 | 0 | NULL | | 40365705 | 2013-11-15 04:57:09 | 1384509433 | 678 | NI | | 40365731 | 2013-11-15 04:58:24 | 1384509504 | 0 | NULL | | 40365733 | 2013-11-15 04:58:24 | 1384509508 | 288 | A | | 40365749 | 2013-11-15 04:59:03 | 1384509543 | 0 | NULL | | 40365751 | 2013-11-15 04:59:03 | 1384509546 | 1247 | A | | 40365781 | 2013-11-15 04:59:58 | 1384509598 | 0 | NULL | | 40365782 | 2013-11-15 04:59:58 | 1384509602 | 94 | A | | 40365797 | 2013-11-15 05:00:32 | 1384509632 | 1 | NULL | | 40365798 | 2013-11-15 05:00:33 | 1384509635 | 396 | A | | 40365814 | 2013-11-15 05:01:15 | 1384509675 | 0 | NULL | | 40365815 | 2013-11-15 05:01:15 | 1384509678 | 276 | A | | 40365823 | 2013-11-15 05:01:50 | 1384509710 | 0 | NULL | | 40365824 | 2013-11-15 05:01:50 | 1384509710 | 13 | NULL | | 40365827 | 2013-11-15 05:02:03 | 1384509726 | 464 | A | | 40365842 | 2013-11-15 05:02:46 | 1384509766 | 0 | NULL | | 40365843 | 2013-11-15 05:02:46 | 1384509769 | 45 | A | | 40365850 | 2013-11-15 05:03:07 | 1384509787 | 0 | NULL | | 40365852 | 2013-11-15 05:03:07 | 1384509790 | 153 | A | | 40365867 | 2013-11-15 05:03:37 | 1384509817 | 0 | NULL | | 40365868 | 2013-11-15 05:03:37 | 1384509821 | 171 | NI | | 40366059 | 2013-11-15 05:09:59 | 1384510199 | 0 | NULL | | 40366060 | 2013-11-15 05:09:59 | 1384510203 | 150 | A | | 40366075 | 2013-11-15 05:10:32 | 1384510232 | 0 | NULL | | 40366077 | 2013-11-15 05:10:32 | 1384510235 | 1326 | A | | 40366102 | 2013-11-15 05:11:34 | 1384510294 | 0 | NULL | | 40366103 | 2013-11-15 05:11:34 | 1384510297 | 107 | A | | 40366118 | 2013-11-15 05:12:01 | 1384510321 | 0 | NULL | | 40366119 | 2013-11-15 05:12:01 | 1384510325 | 231 | NI | | 40366137 | 2013-11-15 05:12:48 | 1384510368 | 0 | NULL | | 40366138 | 2013-11-15 05:12:48 | 1384510371 | 1148 | A | | 40366166 | 2013-11-15 05:13:45 | 1384510425 | 0 | NULL | | 40366167 | 2013-11-15 05:13:45 | 1384510429 | 340 | A | | 40366186 | 2013-11-15 05:14:26 | 1384510466 | 0 | NULL | | 40366188 | 2013-11-15 05:14:26 | 1384510468 | 925 | A | | 40366205 | 2013-11-15 05:15:20 | 1384510520 | 0 | NULL | | 40366206 | 2013-11-15 05:15:20 | 1384510524 | 654 | A | | 40366222 | 2013-11-15 05:16:02 | 1384510562 | 0 | NULL | | 40366223 | 2013-11-15 05:16:02 | 1384510565 | 261 | A | | 40366245 | 2013-11-15 05:16:36 | 1384510596 | 0 | NULL | | 40366246 | 2013-11-15 05:16:36 | 1384510600 | 272 | NI | | 40366285 | 2013-11-15 05:17:36 | 1384510656 | 0 | NULL | | 40366286 | 2013-11-15 05:17:36 | 1384510659 | 19 | A | | 40366309 | 2013-11-15 05:18:15 | 1384510695 | 0 | NULL | | 40366310 | 2013-11-15 05:18:15 | 1384510698 | 23 | A | | 40366336 | 2013-11-15 05:18:52 | 1384510732 | 1 | NULL | | 40366337 | 2013-11-15 05:18:53 | 1384510736 | 412 | A | | 40366347 | 2013-11-15 05:19:31 | 1384510771 | 0 | NULL | | 40366348 | 2013-11-15 05:19:31 | 1384510771 | 1 | NI | | 40366384 | 2013-11-15 05:20:33 | 1384510833 | 10 | A | | 40366399 | 2013-11-15 05:21:02 | 1384510866 | 550 | A | | 40366430 | 2013-11-15 05:21:47 | 1384510907 | 1 | NULL | | 40366431 | 2013-11-15 05:21:48 | 1384510911 | 388 | A | | 40366453 | 2013-11-15 05:22:35 | 1384510955 | 0 | NULL | | 40366454 | 2013-11-15 05:22:35 | 1384510958 | 314 | A | | 40366466 | 2013-11-15 05:23:21 | 1384511001 | 0 | NULL | | 40366467 | 2013-11-15 05:23:21 | 1384511006 | 1391 | NI | | 40366483 | 2013-11-15 05:24:25 | 1384511065 | 0 | NULL | | 40366484 | 2013-11-15 05:24:25 | 1384511068 | 933 | A | | 40366503 | 2013-11-15 05:25:24 | 1384511124 | 0 | NULL | | 40366504 | 2013-11-15 05:25:24 | 1384511128 | 79 | A | | 40366511 | 2013-11-15 05:25:47 | 1384511147 | 0 | NULL | | 40366512 | 2013-11-15 05:25:47 | 1384511147 | 16 | NULL | | 40366518 | 2013-11-15 05:26:03 | 1384511166 | 1491 | A | | 40366529 | 2013-11-15 05:27:06 | 1384511226 | 0 | NULL | | 40366530 | 2013-11-15 05:27:05 | 1384511228 | 136 | A | | 40366533 | 2013-11-15 05:27:36 | 1384511256 | 0 | NULL | | 40366534 | 2013-11-15 05:27:36 | 1384511259 | 22 | NI | | 40366543 | 2013-11-15 05:28:33 | 1384511313 | 0 | NULL | | 40366544 | 2013-11-15 05:28:33 | 1384511316 | 482 | A | | 40366559 | 2013-11-15 05:29:15 | 1384511355 | 0 | NULL | | 40366560 | 2013-11-15 05:29:15 | 1384511358 | 846 | A | | 40366571 | 2013-11-15 05:30:00 | 1384511400 | 0 | NULL | | 40366572 | 2013-11-15 05:30:00 | 1384511438 | 578 | A | | 40366586 | 2013-11-15 05:30:38 | 1384511438 | 0 | NULL | | 40366587 | 2013-11-15 05:30:38 | 1384511438 | 21 | NI | | 40366601 | 2013-11-15 05:31:08 | 1384511468 | 8 | NULL | | 40366605 | 2013-11-15 05:31:16 | 1384511509 | 21 | NULL | | 40366624 | 2013-11-15 05:31:49 | 1384511510 | 0 | NULL | | 40366625 | 2013-11-15 05:31:50 | 1384511518 | 21 | NI | | 40366627 | 2013-11-15 05:31:58 | 1384511526 | 0 | NULL | | 40366636 | 2013-11-15 05:32:06 | 1384511526 | 25 | A | | 40366651 | 2013-11-15 05:32:48 | 1384511568 | 23 | NI | | 40366672 | 2013-11-15 05:33:20 | 1384511600 | 20 | NI | | 40366685 | 2013-11-15 05:33:49 | 1384511629 | 24 | A | | 40366695 | 2013-11-15 05:34:18 | 1384511658 | 25 | NI | | 40366710 | 2013-11-15 05:34:51 | 1384511691 | 8 | NI | | 40366728 | 2013-11-15 05:35:39 | 1384511739 | 13 | NI | | 40366771 | 2013-11-15 05:36:47 | 1384511807 | 20 | NI | | 40366779 | 2013-11-15 05:37:10 | 1384511830 | 7 | NI | | 40366788 | 2013-11-15 05:37:30 | 1384511850 | 21 | A | | 40366798 | 2013-11-15 05:37:58 | 1384511878 | 35 | NI | | 40366817 | 2013-11-15 05:38:44 | 1384511924 | 1 | A | | 40366821 | 2013-11-15 05:38:50 | 1384511930 | 6 | N | | 40366831 | 2013-11-15 05:39:09 | 1384511949 | 10 | A | | 40366839 | 2013-11-15 05:39:23 | 1384511963 | 15 | NI | | 40366853 | 2013-11-15 05:39:47 | 1384511987 | 27 | A | | 40366868 | 2013-11-15 05:40:18 | 1384512018 | 22 | A | | 40366882 | 2013-11-15 05:40:45 | 1384512045 | 22 | A | | 40366888 | 2013-11-15 05:41:11 | 1384512071 | 13 | NULL | | 40366895 | 2013-11-15 05:41:24 | 1384512087 | 313 | NI | | 40366922 | 2013-11-15 05:42:34 | 1384512154 | 0 | NULL | | 40366923 | 2013-11-15 05:42:34 | 1384512158 | 478 | NI | | 40366943 | 2013-11-15 05:43:29 | 1384512213 | 0 | NULL | | 40366950 | 2013-11-15 05:43:29 | 1384512243 | 1010 | A | | 40366974 | 2013-11-15 05:45:15 | 1384512315 | 0 | NULL | | 40366975 | 2013-11-15 05:45:15 | 1384512367 | 287 | A | | 40366990 | 2013-11-15 05:46:06 | 1384512370 | 0 | NULL | | 40366994 | 2013-11-15 05:46:10 | 1384512370 | 3 | NULL | | 40366997 | 2013-11-15 05:46:13 | 1384512373 | 0 | NULL | +--------------+---------------------+------------+----------+--------+ 417 rows in set (4.15 sec)

Seems that it's inserting incorrect wait time to the db.

found a related topic: viewtopic.php?p=62409 does not tell you much though

Yeah.

by **DomeDan** » Fri Nov 15, 2013 7:05 am

have you removed AST_cleanup_agent_log.pl from crontab?

by **PierreDeux** » Fri Nov 15, 2013 7:56 am

DomeDan wrote:have you removed AST_cleanup_agent_log.pl from crontab?

Code: Select all: ### fix the vicidial_agent_log once every hour 33 * * * * /usr/share/astguiclient/AST_cleanup_agent_log.pl

No

Btw I've checked many agents time logs and seems that all of them (or at least most) are affected by the issue. However if some have really huge difference between logged in time and summary of all activities (talk, pause, wait, etc), others have a small difference, but if total activity time is more, than logged in time even for a minute - that's already an issue.

by **DomeDan** » Fri Nov 15, 2013 9:20 am

Find out the system load of the database and web server at the moment the problem occur
leave a loop running the uptime command every minute
while true; do uptime; sleep 60; done
or similar and compare it to the vicidial_agent_log

when you ran the "upgrade_patch_name(2.4,2.6,2.8 ).sql" files
did you run them in the order 2.4, 2.6, 2.8?

by **PierreDeux** » Fri Nov 15, 2013 10:58 am

DomeDan wrote:Find out the system load of the database and web server at the moment the problem occur
leave a loop running the uptime command every minute
while true; do uptime; sleep 60; done
or similar and compare it to the vicidial_agent_log

All servers load is constantly monitored here, if it goes higher, than it should - I would be aware of that.

DomeDan wrote:when you ran the "upgrade_patch_name(2.4,2.6,2.8 ).sql" files
did you run them in the order 2.4, 2.6, 2.8?

Sure thing.

So I ended up installing vicibox iso in a VM and checked default crontabs there. Found this one missing on my production servers:

Code: Select all: 50 0 * * * /usr/share/astguiclient/AST_cleanup_agent_log.pl --last-24hours

I ran it manually and seems that it edited a lot of records in the vicidial_agent_log table. Here is a comparison of before and after.

I checked the code of AST_cleanup_agent_log.pl and it has pretty a lot of options there, including -one-minute-run. I will ask my guys to check what exactly this script does tomorrow, but from what I guess:
1. Hourly run does not do the same, as --last-24hours
2. You don't have exact time stats before running AST_cleanup_agent_log.pl
3. Time values inserted in in the DB are incorrect (sic)?
4. All this looks pretty "vicidial-like"

by **DomeDan** » Mon Nov 18, 2013 4:52 am

Oh, I got both the AST_cleanup_agent_log.pl without arguments and with --last-24hours, but didnt know --last-24hours was required

Looked it up and found that --last-24hours will set the variable $VAL_validate which will make the script run "vicidial_agent_log sec validation"
and basically what that does it that it looks if "event_time" + "wait/pause/talk/dispo sec" equals next events "event_time"
if it does not then it change the "wait/pause/talk/dispo sec" to match up with the next event_time

I did a run with --last-24hours --debugX and it updated a few records

- finished validation of vicidial_agent_log sec fields:
records scanned/corrected: 242 / 20
PAUSE updates: 0
WAIT updates: 6
TALK updates: 0
DISPO updates: 14
DEAD updates: 0
EPOCH updates: 4
distinct users: 5

here is a list of other options what will run "vicidial_agent_log sec validation":
--no-time-restriction
--one-day-ago
--last-30days
--one-minute-run
--more-than-24hours

I would too like to know why there are so many incorrect DB entries..

vicidial.org

Agent wait time gone crazy

Agent wait time gone crazy

Re: Agent wait time gone crazy

Re: Agent wait time gone crazy

Re: Agent wait time gone crazy

Re: Agent wait time gone crazy

Re: Agent wait time gone crazy

Re: Agent wait time gone crazy

Re: Agent wait time gone crazy

Re: Agent wait time gone crazy

Re: Agent wait time gone crazy

Re: Agent wait time gone crazy

Re: Agent wait time gone crazy

Who is online