[Dovecot] DoveCot IMAP and "inconsistent state" messages

Chris Richards gizmo at giz-works.com
Mon Mar 31 23:10:59 EEST 2008 

I need some help troubleshooting this problem.  It only shows up with 
IMAP connections.  I initially thought it was related to SquirrelMail 
(because it gives me an 'EXPUNGE' error), but after attempting to send 
IMAP commands directly to the server as shown below, I'm thinking there 
is something else going on.

The system configuration is PostFix as the MTA delivering to procmail in 
the mailbox (maildir format), with Dovecot handling POP3 and IMAP

Postfix is version 2.3.3
Dovecot is version 1.0.rc15
procmail is version 3.22 2001/09/10
kernel is 2.6.18-53.1.14.el5, CentOS 5

There is additional info about the system configuration after the 
command sequence and log entries below.  I've left my typos in, just in 
case they somehow bear on the problem.  I omitted about 2050 messages 
from the mailbox FETCH listing, since they were all identical but for 
the message number, and I didn't figure you'd want to read all of that.  :)

Command sequence:
[me at myserver~]$ telnet locahost 143
locahost/143: Name or service not known
[me at myserver~]$ telnet localhost 143
Trying 127.0.0.1...
Connected to localhost.localdomain (127.0.0.1).
Escape character is '^]'.
* OK myserver awaiting command
login me mypass
login BAD Error in IMAP command received by server.
a001 login me mypass
a001 OK Logged in.
a002 list "Mail" "*"
a002 OK List completed.
a003 list "Folders" "*"
a003 OK List completed.
a004 list "Inbox"
a004 BAD Error in IMAP command LIST: Invalid arguments.
a005 list "Inbox" "*"
* LIST (\HasNoChildren) "." "INBOX"
a005 OK List completed.
a006 list "" "*"
* LIST (\HasNoChildren) "." "Drafts"
* LIST (\HasNoChildren) "." "Spam"
* LIST (\HasNoChildren) "." "Trash"
* LIST (\HasNoChildren) "." "Sent"
* LIST (\HasNoChildren) "." "INBOX"
a006 OK List completed.
* FLAGS (\Answered \Flagged \Deleted \Seen \Draft)
* OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft \*)] 
Flags permitted.
* 2088 EXISTS
* 1 RECENT
* OK [UNSEEN 2088] First unseen.
* OK [UIDVALIDITY 1190322195] UIDs valid
* OK [UIDNEXT 89700] Predicted next UID
a007 OK [READ-WRITE] Select completed.
a008 FETCH l:* FLAGS
a008 BAD Error in IMAP command FETCH: Invalid messageset
a008 FETCH 1:* FLAGS
* 1 FETCH (FLAGS (\Seen))
* 2 FETCH (FLAGS (\Seen))
* 3 FETCH (FLAGS (\Seen))
* 4 FETCH (FLAGS (\Seen))
* 5 FETCH (FLAGS (\Seen))
* 6 FETCH (FLAGS (\Seen))
.
.
.
* 2083 FETCH (FLAGS (\Seen))
* 2084 FETCH (FLAGS (\Seen))
* 2085 FETCH (FLAGS (\Seen))
* 2086 FETCH (FLAGS (\Seen))
* 2087 FETCH (FLAGS (\Seen))
* 2088 FETCH (FLAGS (\Recent))
* BYE Mailbox is in inconsistent state, please relogin.
Connection closed by foreign host.


These are the corresponding entries from my mail syslog during the same 
time period.  I've included the postfix entries, as they might be 
relevant to the problem.

Mar 31 13:55:14 myserver dovecot: imap-login: Login: user=<me>, 
method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured
Mar 31 13:55:33 myserver dovecot: pop3-login: Login: user=<me>, 
method=PLAIN, rip=xxx.xxx.xxx.xxx, lip=yyy.yyy.yyy.yyy
Mar 31 13:55:35 myserver dovecot: POP3(me): Disconnected: Logged out 
top=0/0, retr=1/18590, del=2/2089, size=10863040
Mar 31 13:56:29 myserver postfix/smtpd[26589]: connect from 
unknown[79.165.160.211]
Mar 31 13:56:30 myserver postfix/smtpd[26589]: 1A57E2F7E6: 
client=unknown[79.165.160.211]
Mar 31 13:56:30 myserver postfix/cleanup[26646]: 1A57E2F7E6: 
message-id=<000901c89360$061afdf8$11e5c1ae at qawbud>
Mar 31 13:56:35 myserver postfix/qmgr[2254]: 1A57E2F7E6: 
from=<amsonson at impsat.com.ar>, size=61232, nrcpt=1 (queue active)
Mar 31 13:56:36 myserver postfix/smtpd[26651]: connect from 
localhost.localdomain [127.0.0.1]
Mar 31 13:56:36 myserver postfix/smtpd[26651]: C98262F893: 
client=localhost.localdomain [127.0.0.1]
Mar 31 13:56:36 myserver postfix/cleanup[26646]: C98262F893: 
message-id=<000901c89360$061afdf8$11e5c1ae at qawbud>
Mar 31 13:56:36 myserver postfix/smtpd[26651]: disconnect from 
localhost.localdomain [127.0.0.1]
Mar 31 13:56:36 myserver amavis[26499]: (26499-03) Passed SPAMMY, 
[79.165.160.211] [79.165.160.211] <amsonson at impsat.com.ar> -> 
<me at digitalvoice.com>, Message-ID: 
<000901c89360$061afdf8$11e5c1ae at qawbud>, mail_id: 47TfQi44++zM, Hits: 
17.608, size: 61232, queued_as: C98262F893, 1372 ms
Mar 31 13:56:36 myserver postfix/smtp[26648]: 1A57E2F7E6: 
to=<me at mydomain.com>, orig_to=<postmaster at digitalvoice.com>, 
relay=127.0.0.1[127.0.0.1]:10024, delay=6.8, delays=5.4/0.01/0.01/1.4, 
dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as C98262F893)Mar 31 
13:56:36 myserver postfix/qmgr[2254]: C98262F893: 
from=<amsonson at impsat.com.ar>, size=62235, nrcpt=1 (queue active)
Mar 31 13:56:36 myserver postfix/qmgr[2254]: 1A57E2F7E6: removed
Mar 31 13:56:36 myserver postfix/local[26653]: C98262F893: 
to=<me at mydomain.com>, relay=local, delay=0.12, delays=0.1/0.01/0/0.01, 
dsn=2.0.0, status=sent (delivered to command: /usr/bin/procmail)
Mar 31 13:56:36 myserver postfix/qmgr[2254]: C98262F893: removed
Mar 31 13:58:07 myserver dovecot: pop3-login: Login: user=<someone>, 
method=PLAIN, rip=xxx.xxx.xxx.xxx, lip=yyy.yyy.yyy.yyy
Mar 31 13:58:07 myserver dovecot: POP3(someone): Disconnected: Logged 
out top=0/0, retr=0/0, del=0/291, size=11570114
Mar 31 14:00:58 myserver dovecot: IMAP(me): Maildir /home/me/.Maildir 
sync: UID inserted in the middle of mailbox (85953 > 85053, file = 
msg.XL7B:2,)
Mar 31 14:00:58 myserver dovecot: IMAP(me): Disconnected: Mailbox is in 
inconsistent state, please relogin.

output of dovecot -n:
# /etc/dovecot.conf
listen: *
login_dir: /var/run/dovecot/login
login_executable(default): /usr/libexec/dovecot/imap-login
login_executable(imap): /usr/libexec/dovecot/imap-login
login_executable(pop3): /usr/libexec/dovecot/pop3-login
login_greeting: myserver awaiting command
mail_location: maildir:~/.Maildir
mail_executable(default): /usr/libexec/dovecot/imap
mail_executable(imap): /usr/libexec/dovecot/imap
mail_executable(pop3): /usr/libexec/dovecot/pop3
mail_plugin_dir(default): /usr/lib/dovecot/imap
mail_plugin_dir(imap): /usr/lib/dovecot/imap
mail_plugin_dir(pop3): /usr/lib/dovecot/pop3
auth default:
  mechanisms: plain login
  passdb:
    driver: pam
  userdb:
    driver: passwd
  socket:
    type: listen
    client:
      path: /var/spool/postfix/private/auth
      mode: 432
      user: postfix
      group: postdrop
    master:


So, now I've got two questions:

   1. Is accessing a mailbox via POP3 and IMAP at the same time
      considered to be a Bad Thing?
   2. Is having procmail drop messages directly into the directory that
      the IMAP process is scanning a Bad Thing?
   3. Is there a better/preferred way to have Postfix/procmail deliver
      mail to the maildir that will keep Dovecot IMAP happy? (There
      don't seem to be any issues with pure POP3 access).


Thanks in advance for your help, and if there's anything else you need 
to know that I can provide, please ask.  I've tried to provide as much 
information up front as I can.

Later,
Chris

More information about the dovecot mailing list