I am configuring and testing an Asterisk 1.6 system that will replace a current 1.4 system. I am anxious to get IMAP voicemail working. The problem is that the IMAP VM system intermittently won’t work. I seem to have Asterisk IMAP configured properly and talking with my Zimbra server, as voicemail it will save voicemail in the proper mailbox most of the time. But VM’s often fail to show up in the IMAP mailbox, particularly when I hit redial w/in 10sec of hanging up from a successful voicemail. And also when concurrent calls go to the same extension’s voicemail, the one that goes to voicemail second won’t make it (I have not tested more than these scenarios and this testing wasn’t very extensive).
The failures look like this: when a call goes to VM, it plays the greeting, but instead of getting the ‘beep’, I get the message ‘sorry, but the user’s mailbox can’t accept more messages’. Then Asterisk hangs up and no voicemail is saved in the IMAP folder. A warning like this is then entered in the full log:
Each failure like this generates a pretty random large number in the place where the ‘475639904’ shows up, even though there are never more than 5 messages in that folder at any one time.
I am wondering if there is a limit on concurrent calls going to the same vm box. I am also wondering if anyone has any suggestions on ways to tweak Asterisk or UW IMAP so that this will work reliably.
(If anyone has comments on the reliability of the IMAP voicemail system in Asterisk 1.6, please voice your opinion.)
Asterisk 1.6.1.1
FreePBX 2.6.0.0
CentOS 5.3
UW IMAP 2007e
Zimbra CS 5.0.14
Here is the Full Log with Debug and Verbose turned on (filtered for app_voicemail) on a failure when calling into voicemail for extension 325 from extension 325. Note the inconsistent and very high Messagecount value that is returned in each case. Because of it, the vm system never makes it to the record phase for the vm.
[Dec 7 15:41:40] DEBUG[14926] app_voicemail.c: Before find_user
[Dec 7 15:41:40] DEBUG[14926] app_voicemail.c: /var/spool/asterisk/voicemail/default/325/busy doesn't exist, doing what we can
[Dec 7 15:41:50] DEBUG[14926] app_voicemail.c: Mailbox is set to 325
[Dec 7 15:41:50] DEBUG[14926] app_voicemail.c: Returning before search - user is logged in
[Dec 7 15:41:50] DEBUG[14926] app_voicemail.c: Returning before search - user is logged in
[Dec 7 15:41:50] DEBUG[14926] app_voicemail.c: comparing mailbox 325@default (i=0) to vmstate mailbox 314@default (i=0)
[Dec 7 15:41:50] DEBUG[14926] app_voicemail.c: comparing mailbox 325@default (i=0) to vmstate mailbox 325@default (i=0)
[Dec 7 15:41:50] DEBUG[14926] app_voicemail.c: Found it!
[Dec 7 15:41:50] DEBUG[14926] app_voicemail.c: Messagecount set to 1077952576
[Dec 7 15:41:50] DEBUG[14926] app_voicemail.c: Mailbox name set to: !Voicemail, about to check quotas
[Dec 7 15:41:50] DEBUG[14926] app_voicemail.c: User myname@domain.com usage is 265175, limit is 3145728
[Dec 7 15:41:50] WARNING[14926] app_voicemail.c: Unable to leave message since we will exceed the maximum number of messages allowed (1077952576 > 100)
[Dec 7 15:55:28] DEBUG[14957] app_voicemail.c: Before find_user
[Dec 7 15:55:28] DEBUG[14957] app_voicemail.c: /var/spool/asterisk/voicemail/default/325/busy doesn't exist, doing what we can
[Dec 7 15:55:38] DEBUG[14957] app_voicemail.c: Mailbox is set to 325
[Dec 7 15:55:38] DEBUG[14957] app_voicemail.c: Returning before search - user is logged in
[Dec 7 15:55:38] DEBUG[14957] app_voicemail.c: Returning before search - user is logged in
[Dec 7 15:55:38] DEBUG[14957] app_voicemail.c: comparing mailbox 325@default (i=0) to vmstate mailbox 314@default (i=0)
[Dec 7 15:55:38] DEBUG[14957] app_voicemail.c: comparing mailbox 325@default (i=0) to vmstate mailbox 325@default (i=0)
[Dec 7 15:55:38] DEBUG[14957] app_voicemail.c: Found it!
[Dec 7 15:55:38] DEBUG[14957] app_voicemail.c: Messagecount set to 1600742497
[Dec 7 15:55:38] DEBUG[14957] app_voicemail.c: Mailbox name set to: !Voicemail, about to check quotas
[Dec 7 15:55:38] DEBUG[14957] app_voicemail.c: User myname@domain.com usage is 265249, limit is 3145728
[Dec 7 15:55:38] WARNING[14957] app_voicemail.c: Unable to leave message since we will exceed the maximum number of messages allowed (1600742497 > 100)
Here is what it looks like when a voicemail succeeds:
[Dec 7 16:09:25] DEBUG[15018] app_voicemail.c: Before find_user
[Dec 7 16:09:25] DEBUG[15018] app_voicemail.c: /var/spool/asterisk/voicemail/default/325/busy doesn't exist, doing what we can
[Dec 7 16:09:35] DEBUG[15018] app_voicemail.c: Mailbox is set to 325
[Dec 7 16:09:35] DEBUG[15018] app_voicemail.c: Returning before search - user is logged in
[Dec 7 16:09:35] DEBUG[15018] app_voicemail.c: Returning before search - user is logged in
[Dec 7 16:09:35] DEBUG[15018] app_voicemail.c: comparing mailbox 325@default (i=0) to vmstate mailbox 314@default (i=0)
[Dec 7 16:09:35] DEBUG[15018] app_voicemail.c: comparing mailbox 325@default (i=0) to vmstate mailbox 325@default (i=0)
[Dec 7 16:09:35] DEBUG[15018] app_voicemail.c: Found it!
[Dec 7 16:09:35] DEBUG[15018] app_voicemail.c: Messagecount set to 0
[Dec 7 16:09:35] DEBUG[15018] app_voicemail.c: Mailbox name set to: !Voicemail, about to check quotas
[Dec 7 16:09:35] DEBUG[15018] app_voicemail.c: User myname@domain.com usage is 265978, limit is 3145728
[Dec 7 16:09:36] VERBOSE[15018] app_voicemail.c: -- Recording the message
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: Storing file '/var/spool/asterisk/voicemail/default/325/INBOX/msg0000', format 'wav'
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: vm_state user is:myname@domain.com
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: Before mail_open, server: {mail.domain.com:143/imap/authuser=admin@domain.com/notls/user=myname@domain.com}!Voicemail, box:0
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: IMAP Info: Reusing connection to mail.domain.com/user="myname@domain.com"
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: Entering EXISTS callback for message 8
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: User myname@domain.com mailbox set for update.
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: IMAP Info: [UNSEEN 8] mailbox contains unseen messages
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: IMAP Info: [HIGHESTMODSEQ 148053] modseq tracked on this mailbox
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: Entering EXISTS callback for message 9
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: User myname@domain.com mailbox set for update.
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: IMAP Info: [APPENDUID 145698 34292] APPEND completed
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: /var/spool/asterisk/voicemail/default/325/INBOX/msg0000 stored
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: Returning before search - user is logged in
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: Returning before search - user is logged in
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: *** Checking if we can expunge, expungeonhangup set to 1
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: Entering EXPUNGE callback for message 4
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: User myname@domain.com mailbox set for update.
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: Entering EXPUNGE callback for message 4
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: User myname@domain.com mailbox set for update.
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: Entering EXPUNGE callback for message 4
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: User myname@domain.com mailbox set for update.
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: Entering EXPUNGE callback for message 4
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: User myname@domain.com mailbox set for update.
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: Entering EXISTS callback for message 5
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: User myname@domain.com mailbox set for update.
[Dec 7 16:09:40] DEBUG[15018] app_voicemail.c: IMAP Info: EXPUNGE completed
[Dec 7 16:09:40] DEBUG[14895] app_voicemail.c: Mailbox is set to 325@default
[Dec 7 16:09:40] DEBUG[14895] app_voicemail.c: Returning before search - user is logged in
[Dec 7 16:09:40] DEBUG[14895] app_voicemail.c: Returning before search - user is logged in
[Dec 7 16:09:40] DEBUG[14895] app_voicemail.c: Returning before search - user is logged in