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@myserver~]$ telnet locahost 143 locahost/143: Name or service not known [me@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@qawbud Mar 31 13:56:35 myserver postfix/qmgr[2254]: 1A57E2F7E6: from=amsonson@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@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@impsat.com.ar -> me@digitalvoice.com, Message-ID: 000901c89360$061afdf8$11e5c1ae@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@mydomain.com, orig_to=postmaster@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@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@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:
- Is accessing a mailbox via POP3 and IMAP at the same time considered to be a Bad Thing?
- Is having procmail drop messages directly into the directory that the IMAP process is scanning a Bad Thing?
- 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