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:
[EMAIL PROTECTED] telnet locahost 143
locahost/143: Name or service not known
[EMAIL PROTECTED] 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=<[EMAIL PROTECTED]>
Mar 31 13:56:35 myserver postfix/qmgr[2254]: 1A57E2F7E6:
from=<[EMAIL PROTECTED]>, 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=<[EMAIL PROTECTED]>
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] <[EMAIL PROTECTED]> ->
<[EMAIL PROTECTED]>, Message-ID:
<[EMAIL PROTECTED]>, 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=<[EMAIL PROTECTED]>, orig_to=<[EMAIL PROTECTED]>,
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=<[EMAIL PROTECTED]>, 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=<[EMAIL PROTECTED]>, 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
