[Home]

Summary:ASTERISK-12312: IMAP (apparently) causing system crash
Reporter:Mike Thomas (mthomasslo)Labels:
Date Opened:2008-07-03 14:47:31Date Closed:2008-07-08 16:01:40
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Applications/app_voicemail
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) app_voicemail_make_errors.txt
Description:Intermittently, and without any apparent pattern, the system will stop responding.  For each failure (3 within the past 3 days) the message log has two IMAP warnings immediately prior to the crash:

WARNING[xxxxx] app_voicemail.c: IMAP Warning: Unexpected tagged response: 0000ad5d OK SEARCH completed

WARNING[xxxxx] app_voicemail.c: IMAP Warning: Unexpected tagged response: 000cb22f OK [APPENDUID 1 287] APPEND completed

WARNING[xxxxx] app_voicemail.c: IMAP Warning: Unexpected tagged response: 000cb420 OK [READ-WRITE]SELECT completed

WARNING[xxxxx] app_voicemail.c: IMAP Warning: Unexpected tagged response: 000ad5d OK SEARCH completed

WARNING[xxxxx] app_voicemail.c: IMAP Warning: Unexpected tagged response: 0000ee4c OK FETCH completed

WARNING[xxxxx] app_voicemail.c: IMAP Warning: Unexpected tagged response: 0000ad66 OK NOOP completed




****** ADDITIONAL INFORMATION ******

IMAP system is a Zimbra Enterprise Server v5.0.6
IMAP client is 2004g
Comments:By: Mark Michelson (mmichelson) 2008-07-03 14:53:48

The unexpected responses mean that to the IMAP c-client it is apparently getting responses to requests it doesn't know about. I would suspect that this problem is a c-client problem. A backtrace of the crash would help to confirm this. Also, you are using a very outdated version of the c-client. I would suggest upgrading to one of the 2007 versions to see if that helps any.
By: Mike Thomas (mthomasslo) 2008-07-03 15:02:58

I will update the c-client, however I noticed on the Forum the following:

http://forums.digium.com/viewtopic.php?p=73028&sid=38fefba16c66a1ba27f33b7f25794ca7

Where another user is experiencing the same problem.  He's using 2007a


By: Mark Michelson (mmichelson) 2008-07-03 15:06:53

Ah, if you could upload a backtrace from the crash, that would be most appreciated. I'm interested still in seeing if the crash seems to stem from Asterisk or from the c-client. Instructions for getting a backtrace may be found in doc/backtrace.txt of the Asterisk source.
By: Mike Thomas (mthomasslo) 2008-07-03 15:43:54

This may not be a "crash" in the traditional sense.  I say this because although the system is running under safe_asterisk (the -g is in there), when the problem occurs the system stops processing calls, but doesn't react as a crash would. ie. The service doesn't restart.  To get it back I have to enter from the CLI "stop now".  The system can then be restarted with "safe_asterisk" and resumes normal operation.  Thus no core dumps are generated.
By: Mark Michelson (mmichelson) 2008-07-03 17:19:15

Hmm, okay, this sounds somewhat similar to reports I have heard before about using IMAP storage. This problem happens due to the fact that MWI is being sent to the phone. In order to get the number of messages available, the IMAP mailbox has to be polled. The unresponsiveness tells me that the c-client is blocking forever most likely in a call to connect(2).

I fixed this problem in the trunk version of Asterisk by allowing TCP timeouts to be configured in voicemail.conf. I'm going to push to have the feature backported.


By: Mike Thomas (mthomasslo) 2008-07-07 10:21:30

First I tried to use the trunk version of app_voicemail in a make of 1.4.20.1, but this resulted in many compile errors (undeclared variables etc.) so I abandoned that idea.
Second I installed svn trunk in it's entireity, but this didn't work very well.  System would crash on segmentation errors about once a minute.
Third, I noticed that 1.6.0 beta 9 uses a similar version of voicemail so I installed that, and observed the following four problems:
1. the "new" prompt is called by the app with vm-Inbox.gsm at times and vm-INBOX.gsm at others.  The make only installs vm-INBOX.gsm.  (I copied the file with the other name to correct this).
2. When the gain is set to anything other than zero, the "volumne" increases (or decreases) each time the message is forwarded.
3. When attempting to forward a message with appended comments, it fails with the logged entry "Warning{xxxxx]: app_voicemail.c: 1860 copy: Unable to open /var/spool/asterisk/voicemail/default/<box number>//msg0000.txt in read-only mode"
4. Comedian Mail hangs-up call after saving a message to the "old" folder.

Then the major problem, after working properly for about 5 minutes, the system crashed completely with the logged entry "ERROR{xxxxx}: app_voicemail.c:9592 mm_fatal: IMAP access FATAL error: Unlock when not locked Aborted"

I gave up and have temporarily gone back to 1.4.20.1 using the traditional message storage.
By: Digium Subversion (svnbot) 2008-07-07 12:26:46

Repository: asterisk
Revision: 128690

U   trunk/apps/app_voicemail.c

------------------------------------------------------------------------
r128690 | mmichelson | 2008-07-07 12:26:45 -0500 (Mon, 07 Jul 2008) | 5 lines

Get app_voicemail compiling when IMAP storage is used.

Brought up by reporter on issue ASTERISK-12312


------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=128690
By: Mark Michelson (mmichelson) 2008-07-07 12:44:37

I have fixed the compilation issues with IMAP voicemail in trunk.

Now to address the numbered points you have posted:
1. I'm not sure where or how this is happening. I grepped the source for "vm-Inbox" and came up with no results. Do you know how this file is being referenced?

2. Hmm, this makes sense, I suppose. Fixing this could be tricky. If users were guaranteed to always access their voicemail via the phone, I would suggest that the gain setting could be stored as an e-mail header and then applied when the voicemail user actually listens to the message on the phone. The problem is that since users may access the messages via an e-mail client instead, we're forced to store the message with the volume adjustment applied already. I suppose that we can somehow determine if the gain has already been applied to that message so that we don't re-adjust when the message is e-mailed subsequent times.

3. This is a known issue, ASTERISK-12118. I have been working on it but have not yet found the exact cause for this.

4. This is something I had not heard of before and off the top of my head, I cannot imagine why it is happening.

The fatal "unlock when not locked" error is something that as far as I know, we cannot help. Apparently a thread in the c-client is attempting to unlock a mutex it did not previously lock. Apparently, the c-client aborts when this happens, which means that it brings Asterisk down with it too. I would suggest reporting this to the UW folks since it is something that is their bug.

As for the four numbered points you made, I would suggest opening new bug reports for issues 2 and 4 since they are legitimate but do not have to do with the originally reported issue. Since issue 3 already has an open bug report associated with it, you can follow it there. As for issue 1, I need some more clarification before I'd suggest opening a bug report for it.
By: Mike Thomas (mthomasslo) 2008-07-07 13:14:00

With respect to item #1, this occurs when Comedian Mail is playing the Message " You have x New messages, press one for NEW messages.  Each of these "NEW"s attempts to play a different file.  When it attempts to play the Inbox file (with lower case "nbox" it hangs up and loggs the following warning "WARNING[xxxxx] file.c: File vm-Inbox does not exist in any format" followed by "WARNING[xxxxx] file.c: Unable to open vm-Inbox (format 0x4 (ulaw)):No such file or directory"  As I indicated simply copying vm-INBOX.gsm to vm-Inbox.gsm (in /var/lib/asterisk/sounds/) was an suitable work-around.
By: Mark Michelson (mmichelson) 2008-07-07 14:44:36

Ah, I think I know what the problem is for item number 1. By any chance, do you have the setting "imapfolder=Inbox" set in voicemail.conf with that exact capitalization? If that's the case, I suspect that the problem is that Asterisk is attempting to play vm-<whatever imap folder is specified>. It just happens to be that in your case, the folder is a different capitalization of a folder name that Asterisk can play correctly.

Of course, if I'm wrong about the setting in voicemail.conf, then I'm back at square one on this one. By the way, that's definitely a bug that you've found, but I want to make sure that I have the correct diagnosis in place before I go about attempting to fix it.
By: Digium Subversion (svnbot) 2008-07-07 15:21:12

Repository: asterisk
Revision: 128731

U   trunk/apps/app_voicemail.c

------------------------------------------------------------------------
r128731 | mmichelson | 2008-07-07 15:21:10 -0500 (Mon, 07 Jul 2008) | 7 lines

If imapfolder=foo were set in voicemail.conf, then when calling VoiceMailMain,
app_voicemail would attempt to play a file called vm-foo instead of playing
vm-INBOX to play the "new" sound file. This commit fixes that issue.

This may fix one of the problems reported in issue ASTERISK-12312


------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=128731
By: Mark Michelson (mmichelson) 2008-07-07 15:34:35

I fixed the problem of having "imapfolder=foo" attempting to play "vm-foo" now. Even if that's not exactly what was affecting you, it was a bug in the code so I fixed it anyway.
By: Mike Thomas (mthomasslo) 2008-07-08 11:51:49

I tried to merge the newest trunk version of app_voicemail.c into 1.4.20.1 and still get the same errors as before when doing the make.  See uploaded text file.
By: Mark Michelson (mmichelson) 2008-07-08 15:19:34

You can't compile trunk modules into Asterisk 1.4. API changes, variable name changes, etc. will cause compilation to fail like you have seen.

I have been working the last two days on attempting to fix forwarding messages when IMAP voicemail is in use. I suppose I can do a quick backport of the timeout options right now though and get this issue closed out.
By: Mark Michelson (mmichelson) 2008-07-08 15:51:01

I have now written the backport of the timeout options for app_voicemail when IMAP storage is used. I will be committing it soon and closing this bug. Please open additional bug reports for issues 2 and 4 which you enumerated earlier. Thanks!
By: Digium Subversion (svnbot) 2008-07-08 16:01:38

Repository: asterisk
Revision: 129158

U   branches/1.4/apps/app_voicemail.c
U   branches/1.4/doc/imapstorage.txt

------------------------------------------------------------------------
r129158 | mmichelson | 2008-07-08 16:01:36 -0500 (Tue, 08 Jul 2008) | 14 lines

Backport TCP-related timeouts to IMAP voicemail in 1.4
since it should solve bugs people are experiencing. Specifically,
there are times where communication with the IMAP server causes
system calls to block forever. If this should happen when querying
the mailbox so that chan_sip's do_monitor thread can send MWI to
a phone, it means that SIP calls cannot be processed any more.

The timeout options are outlined in doc/imapstorage.txt. Defaults
for the timeouts are sixty seconds.

(closes issue ASTERISK-12312)
Reported by: mthomasslo


------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=129158