[Home]

Summary:ASTERISK-07561: [patch] Sometimes missing events in queue_log
Reporter:Morten Tryfoss (mtryfoss)Labels:
Date Opened:2006-08-19 15:10:38Date Closed:2007-07-06 19:18:19
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Applications/app_queue
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) app_queue.patch
( 1) debug-call.log
Description:On some calls the only event I got in queue_log is ENTERQUEUE. I know many of these calls should have exited with EXITWITHKEY (I know, because I log it in another way too).

I've upgraded directly from 1.2.7 to 1.2.10 and then the problem started.
Comments:By: Clod Patry (junky) 2006-08-19 20:47:38

can ya tell me how these calls leave the queues exactly.

By: Morten Tryfoss (mtryfoss) 2006-08-20 05:20:58

Most of these calls leave the queue when the user hits a digit (in our case, 9) to leave his number to be called back.

But, there's also probably some where the caller just hang up (ABANDON).

However, it's hard to reproduce. It just happens 3-4 times during the day with about 150 calls to that queue in total.



By: Serge Vecher (serge-v) 2006-09-06 12:05:54

mtryfoss: if possible, can you please narrow down a release where the breakage first occurs?

By: BJ Weschke (bweschke) 2006-09-06 16:19:26

if we can get DEBUG/VERBOSE logging of where the caller is exiting app_queue, we should be able to see the block of code where they're exiting from and where the log event should fire.

By: Morten Tryfoss (mtryfoss) 2006-09-06 19:47:50

I've downgraded to 1.2.7 and everything is working normaly. Then I tried 1.2.9.1 and there is missing queue events again.

I'm abroad now so I'm not able to do any more debugging this week, but I'll check this when I get back.

By: Morten Tryfoss (mtryfoss) 2006-09-12 05:45:09

I've uploaded the debug/verbose log now.

It's one call that exited without the "EXITWITHKEY".

By: Serge Vecher (serge-v) 2006-10-04 09:23:37

also, is this an issue in 1.2.12.1 / latest 1.2 branch?

By: jmls (jmls) 2006-11-01 12:20:44.000-0600

mtryfoss, is this an issue in 1.2.13 / latest 1.2 branch?

By: Morten Tryfoss (mtryfoss) 2006-11-01 12:50:16.000-0600

Sorry for taking so long, but there's been a lot of work to do and i hasn't been able to upgrade the system. However, I've upgradeded now and I will let you know about the results.

By: Morten Tryfoss (mtryfoss) 2006-11-08 01:31:37.000-0600

I've been testing with 1.2.13 for some time now, and the error still exists.

By: Serge Vecher (serge-v) 2006-11-14 10:31:14.000-0600

I'd still like to see the answer to note ASTERISK-4998335 of possible.

By: Serge Vecher (serge-v) 2006-11-14 10:33:49.000-0600

also, the verbose/debug log bweschke has asked for in 0051385 can be produced per the following instructions:

1) Prepare test environment (reduce the amount of unrelated traffic on the server);
2) Make sure your logger.conf has the following line:
  console => notice,warning,error,debug
3) restart Asterisk with the following command:
  'asterisk -Tvvvvvdddddgc | tee /tmp/verbosedebug.txt'
4) Enable verbose/debug logging with the following CLI commands:
set debug 4
set verbose 4
5) Save complete console log to file and _attach_ said file to the bug.



By: Morten Tryfoss (mtryfoss) 2006-11-15 01:23:49.000-0600

The breakage seemed to start in the 1.2.9 release.

By: Joao Mesquita (jmesquita) 2006-11-30 06:53:16.000-0600

I also have that bug on asterisk 1.2.13 using dynamic queue members or AgentCallBack login, which generated too many deadlocks and I heard chan_agent is being deprecated on 1.4 anyway.
I will try to gather more information on how and when this happens and post it back today if possible.

By: Joao Mesquita (jmesquita) 2006-12-11 08:00:42.000-0600

Ok, I have found some new things about this bug. I added a new ast_log to queue_log right before the last Leave_queue() (line 3243 aprox.) and here's what I found:

  1. Untill now, all ENTERQUEUE events that miss another event are reason = 3, res = 0
  2. A single call generates several ENTERQUEUEs with different call_ids
  3. The first call of all the calls with the same clid (and almost same timestamp) generates a agent FORCEDLOGOFF leaving the queue empty, therefore should be generating a LEAVEEMPTY event on queue_log

Which files should I post?

By: Serge Vecher (serge-v) 2006-12-11 10:37:24.000-0600

jmesquita: see note 0054596

By: Diogenes Eduardo Makibara (dioedu) 2007-02-06 05:48:00.000-0600

I did some changes in app_queue.c and now all leave queue are log. We don't have any ENTERQUEUE without another event like EXITEMPTY. The patch is available here.

By: BJ Weschke (bweschke) 2007-02-06 06:48:15.000-0600

Can anyone that posted the original bug advise on whether this patch fixes things for them? I'm a little skeptical since the original complaints was missing events and this patch only removes additional logging events?

By: Diogenes Eduardo Makibara (dioedu) 2007-02-06 11:41:19.000-0600

bweschke: At really, this patch logs all EXITEMPTY events. Thing that other patch (http://svn.digium.com/view/asterisk/trunk/apps/app_queue.c?rev=24566&r1=24565&r2=24566&view=diff) didn't do. I am doing tests with EXITWITHKEY... Sorry.

By: Joshua C. Colp (jcolp) 2007-02-08 19:42:10.000-0600

bweschke: I suspect the patch was generated in the wrong direction, so it's showing deletions where it should be additions.

By: Serge Vecher (serge-v) 2007-02-09 10:32:57.000-0600

do you mind redoing the patch? Also, please mention your disclaimer status.

By: Serge Vecher (serge-v) 2007-03-30 09:54:03

mtryfoss: does adding the lines from dioedu's patch (not removing them) fix your issues?

By: Joshua C. Colp (jcolp) 2007-06-27 17:47:28

Fixed in 1.2 as of revision 72327, 1.4 as of revision 72328, and trunk as of revision 72330.

By: Digium Subversion (svnbot) 2007-07-04 18:38:36

Repository: asterisk
Revision: 73297

------------------------------------------------------------------------
r73297 | file | 2007-07-04 18:38:34 -0500 (Wed, 04 Jul 2007) | 817 lines

Merged revisions 72207,72232-72233,72241,72258,72261,72274,72304,72325-72326,72329-72330,72332,72337,72354,72358,72382,72384,72437,72452,72454-72457,72466,72490-72492,72494,72524,72539,72555,72557,72598,72600,72666,72670,72700-72701,72706,72727,72738,72741,72767,72807,72867-72869,72889,72920-72923,72927-72932,72935-72940,72982,72986-72987,73003,73006,73054,73127,73144,73174-73175,73191,73209,73254 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

................
r72207 | kpfleming | 2007-06-27 16:13:54 -0300 (Wed, 27 Jun 2007) | 10 lines

Merged revisions 72205 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

........
r72205 | kpfleming | 2007-06-27 14:13:21 -0500 (Wed, 27 Jun 2007) | 2 lines

use the proper type for storing group number bits so that if someone specifies 'group=42' it will actually work instead of being silently ignored

........

................
r72232 | mmichelson | 2007-06-27 16:50:21 -0300 (Wed, 27 Jun 2007) | 10 lines

Adding feature to support the storage and retrieval of voicemail greetings using IMAP storage.
This feature may be turned on by adding imapgreetings=yes to the general section of voicemail.conf
voicemail.conf.sample has details on the options added.

As a result, IMAP storage now has RETRIEVE and DISPOSE macros defined.

In addition to the IMAP greeting changes, I also have added an enum for the voicemail folders
and so now the code should be easier to understand and maintain when it comes to this area.


................
r72233 | file | 2007-06-27 16:57:36 -0300 (Wed, 27 Jun 2007) | 2 lines

Fix -T option. (issue ASTERISK-9767 reported by xylome)

................
r72241 | file | 2007-06-27 17:07:46 -0300 (Wed, 27 Jun 2007) | 2 lines

Fix up properties.

................
r72258 | file | 2007-06-27 17:26:53 -0300 (Wed, 27 Jun 2007) | 18 lines

Merged revisions 72257 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

................
r72257 | file | 2007-06-27 16:25:24 -0400 (Wed, 27 Jun 2007) | 10 lines

Merged revisions 72256 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.2

........
r72256 | file | 2007-06-27 16:23:24 -0400 (Wed, 27 Jun 2007) | 2 lines

I may possibly get shot for doing this... but... defer CDR processing until after the channel has been dealt with. This should eliminate all of the issues with channels going funky (SIP/PRI) when you are posting CDRs to a database that is either slow or unavailable and do not want to enable batching.

........

................

................
r72261 | bbryant | 2007-06-27 17:47:45 -0300 (Wed, 27 Jun 2007) | 20 lines

Merged revisions 72260 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

................
r72260 | bbryant | 2007-06-27 15:46:12 -0500 (Wed, 27 Jun 2007) | 12 lines

Merged revisions 72259 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.2

........
r72259 | bbryant | 2007-06-27 15:43:53 -0500 (Wed, 27 Jun 2007) | 4 lines

Fixes 1000ad when controlling terminal disappears.

Issue ASTERISK-9371, ASTERISK-9710

........

................

................
r72274 | russell | 2007-06-27 18:09:24 -0300 (Wed, 27 Jun 2007) | 21 lines

Merged revisions 72272 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

................
r72272 | russell | 2007-06-27 16:08:34 -0500 (Wed, 27 Jun 2007) | 13 lines

Merged revisions 72267 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.2

........
r72267 | russell | 2007-06-27 16:06:45 -0500 (Wed, 27 Jun 2007) | 5 lines

Fix a minor issue with parsing the priority number.  You could have as much
whitespace as you want around a numeric priority, but you couldn't have any
whitespace around a special priority like "n" or "hint".
(issue ASTERISK-9736, reported by mitheloc, fixed by me)

........

................

................
r72304 | mattf | 2007-06-27 18:44:13 -0300 (Wed, 27 Jun 2007) | 1 line

Let's NOT create a deadlock scenario here
................
r72325 | qwell | 2007-06-27 19:17:59 -0300 (Wed, 27 Jun 2007) | 4 lines

Add support for Thai language in say.c

Issue 9417, patch by dome, with some cleanup done by me.

................
r72326 | qwell | 2007-06-27 19:27:09 -0300 (Wed, 27 Jun 2007) | 4 lines

Fix a segfault when trying to tab complete the "core show uptime" command.

Reported in #asterisk-dev on IRC by jcmoore, fixed by me.

................
r72329 | mmichelson | 2007-06-27 19:47:08 -0300 (Wed, 27 Jun 2007) | 4 lines

Added ability to customize which buttons control forward, reverse, pause, and stop during message playback.
(closes issue 9474, reported and patched by jaroth with modifications by me)


................
r72330 | file | 2007-06-27 19:48:15 -0300 (Wed, 27 Jun 2007) | 18 lines

Merged revisions 72328 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

................
r72328 | file | 2007-06-27 18:45:49 -0400 (Wed, 27 Jun 2007) | 10 lines

Merged revisions 72327 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.2

........
r72327 | file | 2007-06-27 18:43:11 -0400 (Wed, 27 Jun 2007) | 2 lines

Fix issue where queue log events might be missing. (issue ASTERISK-7561 reported by mtryfoss)

........

................

................
r72332 | file | 2007-06-27 19:58:53 -0300 (Wed, 27 Jun 2007) | 10 lines

Merged revisions 72331 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

........
r72331 | file | 2007-06-27 18:58:02 -0400 (Wed, 27 Jun 2007) | 2 lines

Make payload IDs for iLBC/Speex match to our list. Since these are dynamic payloads the other side shouldn't care. (issue ASTERISK-9150 reported by irroot)

........

................
r72337 | bbryant | 2007-06-27 20:04:06 -0300 (Wed, 27 Jun 2007) | 18 lines

Merged revisions 72335 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

................
r72335 | bbryant | 2007-06-27 18:03:01 -0500 (Wed, 27 Jun 2007) | 10 lines

Merged revisions 72333 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.2

........
r72333 | bbryant | 2007-06-27 17:58:53 -0500 (Wed, 27 Jun 2007) | 2 lines

Reverted changes for earlier revisions 72259 to 72261. Issue ASTERISK-9371, ASTERISK-9710

........

................

................
r72354 | file | 2007-06-27 20:13:09 -0300 (Wed, 27 Jun 2007) | 2 lines

Add SIPREFERRINGCONTEXT and SIPREFERREDBYHDR variables when a transfer takes place. (issue ASTERISK-8148 reported by jcovert)

................
r72358 | file | 2007-06-27 20:14:39 -0300 (Wed, 27 Jun 2007) | 2 lines

Silly jingle...

................
r72382 | file | 2007-06-27 20:26:46 -0300 (Wed, 27 Jun 2007) | 18 lines

Merged revisions 72381 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

................
r72381 | file | 2007-06-27 19:25:12 -0400 (Wed, 27 Jun 2007) | 10 lines

Merged revisions 72378 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.2

........
r72378 | file | 2007-06-27 19:24:01 -0400 (Wed, 27 Jun 2007) | 2 lines

Update documentation to clarify variable usage with MixMonitor. (issue ASTERISK-9218 reported by netoguy)

........

................

................
r72384 | bbryant | 2007-06-27 20:30:31 -0300 (Wed, 27 Jun 2007) | 19 lines

Merged revisions 72383 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

................
r72383 | bbryant | 2007-06-27 18:29:14 -0500 (Wed, 27 Jun 2007) | 11 lines

Merged revisions 72373 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.2

........
r72373 | bbryant | 2007-06-27 18:22:13 -0500 (Wed, 27 Jun 2007) | 3 lines

Reinstating patch. This actually fixes the problem, however I was running a development branch without it and mistakenly thought it wasn't fixed.
Fixes issue ASTERISK-9710, and ASTERISK-9371: 100