Summary:ASTERISK-20042: Voice Mail with IMAP storage wrong sequence number.
Reporter:Slava Bendersky (volga629)Labels:
Date Opened:2012-06-24 18:38:53Date Closed:2012-07-26 18:05:45
Versions:10.5.1 Frequency of
Environment:CentOS 5.8 x86_64Attachments:
Description:I tried recompile asterisk in different versions of imap. imap2007-e and imap2007-f and system.
All time the same error. I can't really confirm, where the source of issue.
It delivery voicemail to inbox folder not VoiceMail.

   -- x=0, open writing:  /var/spool/asterisk/voicemail/realtime-ldap/101/tmp/4ozdxB format: wav49, 0xe244e18
   -- User hung up
[2012-06-24 19:02:33] ERROR[1300]: app_voicemail_imapstorage.c:2833 mm_log: IMAP Error: IMAP protocol error: parse error: invalid message sequence number: 4
[2012-06-24 19:02:33] ERROR[1300]: app_voicemail_imapstorage.c:2833 mm_log: IMAP Error: parse error: invalid message sequence number: 4

MailServer Zimbra

2012-06-24 19:02:33,252 INFO  [ImapServer-1] [name=volga629@domain.name;mid=7;ip=localip;oip=remoteip;] index - Deferred Indexing: submitted 0 items in 13ms (0.00/sec). (0 items failed to index). IndexDeferredCount now at 0 NumNotSubmitted= 0
2012-06-24 19:02:33,264 INFO  [ImapServer-1] [name=volga629@domain.name;mid=7;ip=localip;oip=remoteip;] imap - selected folder VoiceMail
2012-06-24 19:02:33,265 INFO  [ImapServer-1] [name=volga629@domain.name;mid=7;ip=localip;oip=remoteip;] imap - [ search is: in:"VoiceMail" (-tag:\Deleted -tag:\Flagged -(-tag:\Unread) #x-asterisk-vm-extension:("101*") #x-asterisk-vm-context:("realtime-ldap*")) ]
2012-06-24 19:02:33,270 INFO  [ImapServer-1] [name=volga629@domain.name;mid=7;ip=localip;oip=remoteip;] imap - S: 00000095 BAD parse error: invalid message sequence number: 4

Imap Settings

pbxskip=yes                     ; Don't put [PBX]: in the subject line
serveremail=vm_master@domainname ; Who the e-mail notification should appear to come from
fromstring=VoicemailSystem      ; Real name of email sender
maxsilence=5                    ; Wait for 5 silent seconds and end the voicemail
silencethreshold=128            ; What do we consider to be silence
skipms=3000                     ; How many miliseconds to skip forward/back when rew/ff in message playback
review=yes                      ; Allow sender to review/rerecord their message before saving it
operator=yes                    ; Allow caller to press 0
nextaftercmd=yes                ; Automagically play next message when current message is deleted or saved
Comments:By: Slava Bendersky (volga629) 2012-06-24 19:20:41.751-0500

Here another message which I see, and can't find any explanation about it.

   -- Recording the message
   -- x=0, open writing:  /var/spool/asterisk/voicemail/realtime-ldap/101/tmp/RuZ816 format: wav49, 0xeb00fd8
   -- User hung up
[2012-06-24 20:18:03] WARNING[1555]: app_voicemail_imapstorage.c:1800 vm_imap_delete: msgnum 0, mailbox message 0 is zero.

By: Slava Bendersky (volga629) 2012-06-25 01:31:54.133-0500

After some look around. I see it not delivery email into specific folder in my case VoiceMail. I see local delivery lmtp and Imap-SSL.

By: Matt Jordan (mjordan) 2012-06-25 12:04:20.827-0500

Commenting from our conversation in #asterisk:

(11:18:19 AM) mjordan: volga629: that aside, I'm going to lean on this being your mail server, for two reasons
(11:18:52 AM) mjordan: 1. Your log actually shows a search being performed by Asterisk, and it occurs in the VoiceMail folder, which is what you specified in your configuration.  That implies Asterisk is using that folder name to look for voicemails from your mail server
(11:19:54 AM) mjordan: 2. When the mail server stores the message, it does so in folder "Inbox".  Asterisk always refers to that folder as "INBOX" - if it was Asterisk that was using the default new message folder instead of the one that was overridden, I would expect to see "INBOX" in that INFO statement
(11:20:25 AM) volga629: no that all what I am using for right now, just want make basic happy and after look what next
(11:22:42 AM) volga629: I think that the way zimbra write logs, because I did small test and created sub folder under INBOX and specified like INBOX/VoiceMail and I so it recognized no issue

(11:41:19 AM) volga629: I went though the log and found this [2012-06-25 12:07:24] WARNING[24966] app_voicemail.c: msgnum 0, mailbox message 0 is zero
(11:43:01 AM) mjordan: volga629: when you use IMAP voicemail, messages - including warnings and errors - are reported from the IMAP c-client library.  This can be all sorts of stuff, depending on the interactions between Asterisk and whatever IMAP server is involved.  Sometimes they're benign, other times they're worth exploring, but its a case by case basis
(11:55:17 AM) volga629: I see, just trying understand what right what not

By: Matt Jordan (mjordan) 2012-06-25 12:06:10.806-0500

At this point in time, I do not believe this is an Asterisk issue, but rather an issue with your mail server.

That being said, if you'd like, you can debug where Asterisk is attempting to send the mail message in imap_mailbox_name.  You'll need to modify the source to have it log out the full buffer spec.  That should contain the folder name that the message is being sent to.

Based on the rest of the log from your mailserver, however, it appears as if Asterisk is already attempting to send the message to VoiceMail, and the mailserver is routing it to Inbox because it is a new message.

By: Rusty Newton (rnewton) 2012-06-27 18:40:22.129-0500

Just setting this to waiting on feedback from Slava, since Matts last comment was a request.

By: Slava Bendersky (volga629) 2012-06-27 20:37:43.550-0500

After some look around, I found that messages get delivery through IMAP and deleted right away.  I was need remove delete option from VM user string and right message is delivered to required folder.
See log file from mail server below.

2012-06-26 16:57:50,477 INFO  [ImapServer-45] [name=test@networklab.ca;mid=13;ip=;oip=;] imap - selected folder VoiceMail
2012-06-26 16:57:50,502 INFO  [ImapServer-45] [name=test@networklab.ca;mid=13;ip=;oip=;] mailop - Adding Message: id=265, Message-ID=<Asterisk-1-769223741-101-22671@capbxsrv01.pbxclst.networklab.ca>, parentId=-1, folderId=257, folderName=VoiceMail.
2012-06-26 16:57:50,562 INFO  [ImapServer-45] [name=test@networklab.ca;mid=13;ip=;oip=;] mailop - Deleting Message (id=265).
2012-06-26 16:57:50,634 INFO  [ImapServer-45] [name=test@networklab.ca;mid=13;ip=;oip=;] imap - selected folder VoiceMail

By: Rusty Newton (rnewton) 2012-06-29 09:22:06.483-0500

Slava, great. To confirm, it is working as expected now?