Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads
My Dovecot 2.2.16 server is interacting poorly with a variety of mail clients. The symptoms include disappearing messages, mismatched summaries, duplicated messages, and excessive full re-downloads.
Dovecot 2.2.16 on FreeBSD 10.1-release r280247M ZFS is interacting suboptimally with various email clients. Output of "dovecot -n" further down.
*Client Artifacts*
Thunderbird 31.6 Win 7 Ultimate SP1:
messages disappear and reappear with checks somewhat randomly.
Sometimes full re-download of folders is triggered, also seems random
Copies of messages appear, sometimes multiplying with each mail check up to about 5-8 or so of each message.
The summary information in the list pane doesn't match the message headers in the preview pane
quit and restart always cleans it up.
sometimes changing folders cleans it up, but not always
sometimes instigating a manual mail check cleans it up but not always
Mulberry 4.08 Win 7 Ultimate SP1:
messages disappear and reappear
full re-scans of entire folders triggered occasionally when changing folders, but not always
message list filled with semi-blank entries (message number, status flags, and dates are listed, but no sender, subject, or body is available). The time stamps do not appear to be correct "date received".
message list fills with duplicates - the last of the set of duplicates, which are not necessarily sequentially numbered, has load-able body text and headers, but the others do not. There may be 3-5 copies, only one of which is the real message. The inbox is sequentially numbered by "message number" (the "natural order of the mailbox") and duplicates have unique numbers.
If there's a deleted message left, the "expunge" button is enabled and this also restores normal mailbox view.
disconnecting and reconnecting usually fixes the issues
changing mailboxes while connected sometimes fixes the issues.
Claws 3.10.1 Win 7 Ultimate SP1
- initial load is correct, but once claws tries to sync mail, it locks up and never releases (even after days). Claws is weird like that.
Sylpheed 3.4.2 Win 7 Ultimate SP1
mail list always looks fine, but sometimes clicking a message shows "can't display" in the preview pane
"get messages" restores access to messages.
Thunderbird 31.5 Linux Mint 17 Qaina 3.13.0-24-generic
- messages disappear and reappear with checks somewhat randomly.
- Sometimes full redownload of folders is triggered, also seems random
- Copies of messages appear, sometimes multiplying with each mail check
- The summary information in the list pane doesn't match the message headers in the preview pane
- wrong message total (every other client agrees on 2576 but TB-linux says 3242, perhaps counting dups)
Claws 3.9.3 Linux Mint 17 Qaina 3.13.0-24-generic
Occasionally shows "this message can't be displayed"
executing a "get mail" fixes the error
K-9 5.004 Android 4.3
- messages appear and then disappear on the next check
- message body is occasionally blank (only subject and arrival time appear, no body preview line, clicking on the message shows "no text"
*Server artifacts:*
dovecot.log shows runs of this error: Apr 15 09:02:37 imap(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306286, file=1429102024.M826331P1156.host,S=1678,W=1724:2,S)
or this error: Apr 15 10:04:00 indexer-worker(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306803, file=1428785463.M645546P27215.host,S=5389,W=5442:2,S)
# grep -c "Expunged message reappeared" dovecot.log.0 8981
The first entry in dovecot.log.0 is at Apr 15 10:00:12, and the last entry at Apr 15 12:00:13; Dovecot is logging 4,490 expunged message reappeared messages per hour. Note the server has 4 accounts set up and very limited traffic, so 4,490 per hour would seem like a lot of anything to be logged.
# doveadm dump -t mailboxlog /mail/domain.com/user #0: rename 000000803de108b60f00000000000000 (1969-12-31 16:00:00) #24: 00000000000000000000000000000000 (1969-12-31 16:00:00) #48: 000000000000000000000000c8272100 (1969-12-31 16:01:04) #72: 00002e61726368697665732e32303031 (2031-02-20 10:50:40) Fatal: rec read() 10 != 24
"Fatal" seems like an error. I do not see much argument with the assertion that 10 != 24.
# doveadm dump -t fts-expunge-log /mail/domain.com/user Fatal: Invalid record_size=2147483648 at offset 0
dovecot-debug.log examples follow after # dovecot -n output, which follows "fixes tried:"
*Fixes Tried*
# doveadm purge -A # doveadm fts rescan -u user@domain.com # doveadm -Dv index -u user INBOX # doveadm force-resync -u user INBOX
I've set mbox_dirty_syncs = no mbox_lazy_writes = no
...in an attempt to fix the problem, but none did.
I tried removing most of my customizations one by one and testing, but the problem has not been improved.
I strongly suspect that the index files are getting thrashed or otherwise abused. I have no idea what's triggering whatever event is resulting in the thousands of expunged messages reappearing, but the client artifacts suggest a mismatch between cache or index files and files on disk: UID, keywords, and set date appear as if from cache but the body of the message does not. It seems as if the UID doesn't match a message on disk any more, which soon gets automatically fixed and everything syncs again until something re-triggers - a false expunge perhaps? Or perhaps the transaction log is suffering some sort of ongoing abuse?
*dovecot -n*
# dovecot -n # 2.2.16: /usr/local/etc/dovecot/dovecot.conf # Pigeonhole version 0.4.7 # OS: FreeBSD 10.1-RELEASE amd64 auth_default_realm = blackrosetech.com auth_mechanisms = plain login auth_realms = blackrosetech.com eroticanarchy.org debug_log_path = /var/log/dovecot-debug.log deliver_log_format = msgid=%m: %f $p %$ disable_plaintext_auth = no first_valid_gid = 5000 first_valid_uid = 5000 hostname = blackrosetech.com info_log_path = /var/log/dovecot-info.log last_valid_gid = 5000 last_valid_uid = 5000 lda_mailbox_autocreate = yes listen = 10.3.69.135 log_path = /var/log/dovecot.log mail_debug = yes mail_gid = 5000 mail_location = maildir:~:CONTROL=/var/no-quota/%u mail_plugins = quota mail_log notify fts fts_lucene mail_temp_dir = /var/tmp mail_uid = 5000 managesieve_notify_capability = mailto managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date index ihave duplicate spamtest spamtestplus editheader mbox_dirty_syncs = no mbox_lazy_writes = no namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = } passdb { args = /usr/local/etc/dovecot/dovecot-sql.conf.ext driver = sql } plugin { expire = Trash fts = lucene fts_autoindex = yes fts_lucene = whitespace_chars=@. mime_parts mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename mail_log_fields = uid box msgid size quota = maildir:User quota quota_exceeded_message = Storage quota for this account has been exceeded, please try again later. quota_rule = *:storage=50G quota_rule2 = Trash:storage=+30%% quota_rule3 = Sent:storage=+30%% quota_warning = storage=90%% quota-warning 90 %u quota_warning2 = storage=75%% quota-warning 75 %u sieve = ~/.dovecot.sieve sieve_before = /usr/local/etc/dovecot/sieve/ sieve_dir = ~/sieve sieve_extensions = +spamtest +spamtestplus +relational +comparator-i;ascii-numeric +editheader sieve_global_dir = /usr/local/etc/dovecot/sieve } postmaster_address = gessel@blackrosetech.com protocols = imap lmtp sieve sieve sendmail_path = /usr/local/sbin/sendmail service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } unix_listener auth-userdb { group = vmail mode = 0666 user = vmail } } service managesieve-login { inet_listener sieve { port = 4190 } service_count = 1 vsz_limit = 128 M } service quota-warning { executable = script /usr/local/bin/quota-warning.sh unix_listener quota-warning { user = vmail } user = vmail } ssl = required ssl_cert =
I appreciate any assistance or insight,
-David
*dovecot-debug.log excerpts*
Apr 15 13:17:26 indexer-worker(user@domain.com): user-lookup(user@domain.com)Debug: auth input: user@domain.com home=/mail/domain.com/user/ mail=maildir:~/ uid=5000 gid=5000 quota_rule=*:bytes=0 Apr 15 13:17:26 indexer-worker(user@domain.com): user-lookup(user@domain.com)Debug: Added userdb setting: mail=maildir:~/ Apr 15 13:17:26 indexer-worker(user@domain.com): user-lookup(user@domain.com)Debug: Added userdb setting: plugin/quota_rule=*:bytes=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Effective uid=5000, gid=5000, home=/mail/domain.com/user/ Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=0 messages=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=0 (30%) messages=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=0 (30%) messages=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota warning: bytes=0 (90%) messages=0 reverse=no command=quota-warning 90 user@domain.com Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota warning: bytes=0 (75%) messages=0 reverse=no command=quota-warning 75 user@domain.com Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota grace: root=User quota bytes=0 (10%) Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/ Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: maildir++: root=/mail/domain.com/user/, index=, indexpvt=, control=, inbox=/mail/domain.com/user/, alt= Apr 15 13:17:27 indexer-worker(user@domain.com): Debug: Ignoring unknown cache field: pop3.order Apr 15 13:17:27 indexer-worker(user@domain.com): Debug: Ignoring unknown cache field: binary.parts Apr 15 13:17:27 indexer-worker(user@domain.com): Debug: Ignoring unknown cache field: body.snippet
Apr 15 13:44:25 lda(user@domain.com): Debug: Quota root: name=User quota
backend=maildir args=
Apr 15 13:44:25 lda(user@domain.com): Debug: Quota rule: root=User quota
mailbox=* bytes=53687091200 messages=0
Apr 15 13:44:25 lda(user@domain.com): Debug: Quota rule: root=User quota
mailbox=Trash bytes=+16106127360 (30%) messages=0
Apr 15 13:44:25 lda(user@domain.com): Debug: Quota rule: root=User quota
mailbox=Sent bytes=+16106127360 (30%) messages=0
Apr 15 13:44:25 lda(user@domain.com): Debug: Quota warning:
bytes=48318382080 (90%) messages=0 reverse=no command=quota-warning 90 raw
mail user
Apr 15 13:44:25 lda(user@domain.com): Debug: Quota warning:
bytes=40265318400 (75%) messages=0 reverse=no command=quota-warning 75 raw
mail user
Apr 15 13:44:25 lda(user@domain.com): Debug: Quota grace: root=User quota
bytes=5368709120 (10%)
Apr 15 13:44:25 lda(user@domain.com): Debug: none: root=, index=,
indexpvt=, control=, inbox=, alt=
Apr 15 13:49:32 lda(user@domain.com): Debug: Quota root: name=User quota
backend=maildir args=
Apr 15 13:49:32 lda(user@domain.com): Debug: Quota rule: root=User quota
mailbox=* bytes=53687091200 messages=0
Apr 15 13:49:32 lda(user@domain.com): Debug: Quota rule: root=User quota
mailbox=Trash bytes=+16106127360 (30%) messages=0
Apr 15 13:49:32 lda(user@domain.com): Debug: Quota rule: root=User quota
mailbox=Sent bytes=+16106127360 (30%) messages=0
Apr 15 13:49:32 lda(user@domain.com): Debug: Quota warning:
bytes=48318382080 (90%) messages=0 reverse=no command=quota-warning 90 raw
mail user
Apr 15 13:49:32 lda(user@domain.com): Debug: Quota warning:
bytes=40265318400 (75%) messages=0 reverse=no command=quota-warning 75 raw
mail user
Apr 15 13:49:32 lda(user@domain.com): Debug: Quota grace: root=User quota
bytes=5368709120 (10%)
Apr 15 13:49:32 lda(user@domain.com): Debug: none: root=, index=,
indexpvt=, control=, inbox=, alt=
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file storage: Using
script storage path: /mail/domain.com/user//sieve
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file storage: Relative
path to sieve storage in active link: sieve/
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script Forwards' from /mail/domain.com/user/sieve/Forwards.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_Server_Msg' from /mail/domain.com/user/sieve/File_Server_Msg.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_SRL' from /mail/domain.com/user/sieve/File_SRL.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_BULK' from /mail/domain.com/user/sieve/File_BULK.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_Commerce' from /mail/domain.com/user/sieve/File_Commerce.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_Impersonal' from /mail/domain.com/user/sieve/File_Impersonal.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_Travel' from /mail/domain.com/user/sieve/File_Travel.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_Tribe' from /mail/domain.com/user/sieve/File_Tribe.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_Info' from /mail/domain.com/user/sieve/File_Info.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_Lists' from /mail/domain.com/user/sieve/File_Lists.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_Trash' from /mail/domain.com/user/sieve/File_Trash.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_Security' from /mail/domain.com/user/sieve/File_Security.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_Notifications' from /mail/domain.com/user/sieve/File_Notifications.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened
script File_Spam' from /mail/domain.com/user/sieve/File_Spam.sieve'
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: Script binary
/mail/domain.com/user/.dovecot.svbin successfully loaded
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: binary save: not saving
binary /mail/domain.com/user/.dovecot.svbin, because it is already stored
Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: Executing script from
`/mail/domain.com/user/.dovecot.svbin'
Apr 15 13:49:41 lda(user@domain.com): Debug: Quota root: name=User quota
backend=maildir args=
Apr 15 13:49:41 lda(user@domain.com): Debug: Quota rule: root=User quota
mailbox=* bytes=53687091200 messages=0
Apr 15 13:30:31 imap(user@domain.com): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib15_notify_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib20_mail_log_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_lucene_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Added userdb setting: plugin/quota_rule=*:bytes=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Effective uid=5000, gid=5000, home=/mail/domain.com/user/ Apr 15 13:30:31 imap(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:30:31 imap(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=0 messages=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=0 (30%) messages=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=0 (30%) messages=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Quota warning: bytes=0 (90%) messages=0 reverse=no command=quota-warning 90 user@domain.com Apr 15 13:30:31 imap(user@domain.com): Debug: Quota warning: bytes=0 (75%) messages=0 reverse=no command=quota-warning 75 user@domain.com Apr 15 13:30:31 imap(user@domain.com): Debug: Quota grace: root=User quota bytes=0 (10%) Apr 15 13:30:31 imap(user@domain.com): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~:CONTROL=/var/no-quota/user@domain.com Apr 15 13:30:31 imap(user@domain.com): Debug: maildir++: root=/mail/domain.com/user/, index=, indexpvt=, control=/var/no-quota/user@domain.com, inbox=/mail/domain.com/user/, alt=
mail_location = maildir:~:CONTROL=/var/no-quota/%u
At first glance the above looks like it may be wrong or a typo.
I don't remember now why I added the following, but it seems like it may be worth a shot:
imap_client_workarounds = delay-newmail tb-extra-mailbox-sep tb-lsub-flags
mbox_dirty_syncs = no mbox_lazy_writes = no
Pretty sure the above is for mbox if you are using maildir I don't think they apply, but I could be wrong.
Good luck.
Edgar
Edgar,
Thank you very much for your help.
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Edgar Pettijohn III edgar@pettijohn-web.com To: David Gessel gessel@blackrosetech.com Date: Thu Apr 16 2015 05:10:50 GMT+0300 (Arabic Standard Time)
mail_location = maildir:~:CONTROL=/var/no-quota/%u
At first glance the above looks like it may be wrong or a typo.
It does what I expect: mail directories are virtual and look like
/mail/domain.tld/user/cur /mail/domain.tld/user/.Sent/cur
That's a little different than one would use for home directories where it would make sense to have something like
/usr/home/user/maildir/INBOX/
control ends up looking like
/var/no-quota/user@domain.tld/.INBOX
I suppose "no-quota" was taken a little literally from the examples. I worried a bit that the lack of Maildir in the directory path might confuse something, but so far all clients can enumerate the IMAP structure.
I don't remember now why I added the following, but it seems like it may be worth a shot:
imap_client_workarounds = delay-newmail tb-extra-mailbox-sep tb-lsub-flags
I had tb-extra-mailbox-sep enabled, but on closer read it is only required if LAYOUT=fs, which I am not using so I removed it to simplify my options. I don't think it did anything better or worse being there. The documentation says delay-newmail is for outlook express 6 I haven't seen tb-lsub-flags - it seems to have been introduced in 2011 to help TB understand folders of folders. I'll give it a try, but I don't think it will impact the problems I'm seeing across so many clients.
mbox_dirty_syncs = no mbox_lazy_writes = no
Pretty sure the above is for mbox if you are using maildir I don't think they apply, but I could be wrong.
I think you're right, and that would explain why they make no difference.
Good luck.
Edgar
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
On Thu, 16 Apr 2015, David Gessel wrote:
My Dovecot 2.2.16 server is interacting poorly with a variety of mail clients. The symptoms include disappearing messages, mismatched summaries, duplicated messages, and excessive full re-downloads.
Dovecot 2.2.16 on FreeBSD 10.1-release r280247M ZFS is interacting suboptimally with various email clients. Output of "dovecot -n" further down.
ZFS does have some features, that allow backups and restore and such, if I remember correctly.
dovecot.log shows runs of this error: Apr 15 09:02:37 imap(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306286, file=1429102024.M826331P1156.host,S=1678,W=1724:2,S)
Such message I saw only, when I manually changed files in the Maildir directory. That's why I pointed out ZFS above. Do you use some strategies, that freezes a Maildir, then do something (e.g. backup), then thaw the Maildir. During the backup, a client could delete a message, which reapper after thaw.
Other possibilities: rsync/copy, vi, ... on file system level When you operate on filesystem level on the Maildirs keep in mind, that filenames store message flags and status, which may change regularily.
I've set mbox_dirty_syncs = no mbox_lazy_writes = no
you are using Maildir, no? They don't effect Maildir.
mail_location = maildir:~:CONTROL=/var/no-quota/%u
this one hits me:
http://wiki2.dovecot.org/VirtualUsers/Home "Home directory shouldn't be the same as mail directory. It's possible to do that, but you might run into trouble with it sooner or later. Some problems with this are: " ...
mail_plugins = quota mail_log notify fts fts_lucene
I don't run FTS, where does lucene store its files? In the user's home?
Apr 15 13:17:26 indexer-worker(user@domain.com): user-lookup(user@domain.com)Debug: Added userdb setting: mail=maildir:~/ Apr 15 13:17:26 indexer-worker(user@domain.com): user-lookup(user@domain.com)Debug: Added userdb setting: plugin/quota_rule=*:bytes=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Effective uid=5000, gid=5000, home=/mail/domain.com/user/ Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=0 messages=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=0 (30%) messages=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=0 (30%) messages=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota warning: bytes=0 (90%) messages=0 reverse=no command=quota-warning 90 user@domain.com Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota warning: bytes=0 (75%) messages=0 reverse=no command=quota-warning 75 user@domain.com Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota grace: root=User quota bytes=0 (10%) Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/ Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: maildir++: root=/mail/domain.com/user/, index=, indexpvt=, control=, inbox=/mail/domain.com/user/, alt= Apr 15 13:17:27 indexer-worker(user@domain.com): Debug: Ignoring unknown cache field: pop3.order Apr 15 13:17:27 indexer-worker(user@domain.com): Debug: Ignoring unknown cache field: binary.parts Apr 15 13:17:27 indexer-worker(user@domain.com): Debug: Ignoring unknown cache field: body.snippet
Apr 15 13:44:25 lda(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:44:25 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=53687091200 messages=0 Apr 15 13:44:25 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=+16106127360 (30%) messages=0 Apr 15 13:44:25 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=+16106127360 (30%) messages=0 Apr 15 13:44:25 lda(user@domain.com): Debug: Quota warning: bytes=48318382080 (90%) messages=0 reverse=no command=quota-warning 90 raw mail user Apr 15 13:44:25 lda(user@domain.com): Debug: Quota warning: bytes=40265318400 (75%) messages=0 reverse=no command=quota-warning 75 raw mail user Apr 15 13:44:25 lda(user@domain.com): Debug: Quota grace: root=User quota bytes=5368709120 (10%) Apr 15 13:44:25 lda(user@domain.com): Debug: none: root=, index=, indexpvt=, control=, inbox=, alt= Apr 15 13:49:32 lda(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:49:32 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=53687091200 messages=0 Apr 15 13:49:32 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=+16106127360 (30%) messages=0 Apr 15 13:49:32 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=+16106127360 (30%) messages=0 Apr 15 13:49:32 lda(user@domain.com): Debug: Quota warning: bytes=48318382080 (90%) messages=0 reverse=no command=quota-warning 90 raw mail user Apr 15 13:49:32 lda(user@domain.com): Debug: Quota warning: bytes=40265318400 (75%) messages=0 reverse=no command=quota-warning 75 raw mail user Apr 15 13:49:32 lda(user@domain.com): Debug: Quota grace: root=User quota bytes=5368709120 (10%) Apr 15 13:49:32 lda(user@domain.com): Debug: none: root=, index=, indexpvt=, control=, inbox=, alt= Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file storage: Using script storage path: /mail/domain.com/user//sieve Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file storage: Relative path to sieve storage in active link: sieve/ Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened script
Forwards' from/mail/domain.com/user/sieve/Forwards.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Server_Msg' from/mail/domain.com/user/sieve/File_Server_Msg.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_SRL' from/mail/domain.com/user/sieve/File_SRL.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_BULK' from/mail/domain.com/user/sieve/File_BULK.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Commerce' from/mail/domain.com/user/sieve/File_Commerce.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Impersonal' from/mail/domain.com/user/sieve/File_Impersonal.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Travel' from/mail/domain.com/user/sieve/File_Travel.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Tribe' from/mail/domain.com/user/sieve/File_Tribe.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Info' from/mail/domain.com/user/sieve/File_Info.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Lists' from/mail/domain.com/user/sieve/File_Lists.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Trash' from/mail/domain.com/user/sieve/File_Trash.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Security' from/mail/domain.com/user/sieve/File_Security.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Notifications' from/mail/domain.com/user/sieve/File_Notifications.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Spam' from/mail/domain.com/user/sieve/File_Spam.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: Script binary /mail/domain.com/user/.dovecot.svbin successfully loaded Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: binary save: not saving binary /mail/domain.com/user/.dovecot.svbin, because it is already stored Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: Executing script from `/mail/domain.com/user/.dovecot.svbin' Apr 15 13:49:41 lda(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:49:41 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=53687091200 messages=0Apr 15 13:30:31 imap(user@domain.com): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib15_notify_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib20_mail_log_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_lucene_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Added userdb setting: plugin/quota_rule=*:bytes=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Effective uid=5000, gid=5000, home=/mail/domain.com/user/ Apr 15 13:30:31 imap(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:30:31 imap(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=0 messages=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=0 (30%) messages=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=0 (30%) messages=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Quota warning: bytes=0 (90%) messages=0 reverse=no command=quota-warning 90 user@domain.com Apr 15 13:30:31 imap(user@domain.com): Debug: Quota warning: bytes=0 (75%) messages=0 reverse=no command=quota-warning 75 user@domain.com Apr 15 13:30:31 imap(user@domain.com): Debug: Quota grace: root=User quota bytes=0 (10%) Apr 15 13:30:31 imap(user@domain.com): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~:CONTROL=/var/no-quota/user@domain.com Apr 15 13:30:31 imap(user@domain.com): Debug: maildir++: root=/mail/domain.com/user/, index=, indexpvt=, control=/var/no-quota/user@domain.com, inbox=/mail/domain.com/user/, alt=
Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1
iQEVAwUBVS9dNnz1H7kL/d9rAQLn8Af/cQ8BSg6cmUFj6qGVcQUglJkI8hjY3CQM 2MBI/qQbouo4hg3eQNOLX+MOYAGcCV2I+wM8WkOJkqOjPn8vBZACHe5Y860mBbEA XipvGMML1DJt+4leNo/1jPpiFJEFZ3w9kFiCC+rPcjrTU8XV5g+l9RQDofu8vElZ jySGQvH3Ml7kP2afTrqiBb3cwoQVLXMYUTsjw4csw0qn3lWB7i3yN/WACsBMFBP6 H0KnM99UUYbOJ4TMsBJ7aDXIUIvlu6Eo1oGznIsKiX1k6BoCPQtXwlxk4NJ6f8B/ SaGYf6FPSQmKaePTVwxJfSc8sTBxb+rG7DsZQnGjwZFtGH3ti810eg== =6hFs -----END PGP SIGNATURE-----
Steffen,
Thank you very much for your help. It is very much appreciated.
--On Thursday, April 16, 2015 08:56 +0200 Steffen Kaiser skdovecot@smail.inf.fh-brs.de wrote:
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
On Thu, 16 Apr 2015, David Gessel wrote:
My Dovecot 2.2.16 server is interacting poorly with a variety of mail clients. The symptoms include disappearing messages, mismatched summaries, duplicated messages, and excessive full re-downloads.
Dovecot 2.2.16 on FreeBSD 10.1-release r280247M ZFS is interacting suboptimally with various email clients. Output of "dovecot -n" further down.
ZFS does have some features, that allow backups and restore and such, if I remember correctly.
ZFS can do some awesome things like snapshotting and the like, but they're hidden from the OS (no atime modification if that is enabled, for example) and you can exchange your disks for larger ones and expand into the new space with a single command.
It is possible there is an unexpected interaction between ZFS and Maildir, but a good friend of mine runs Dovecot/Maildir on a BSD 10.0/ZFS system without the issues I'm seeing. I've created a diff of our dovecot -n outputs that I'd be happy to share, but it is a styled HTML file and attachments are usually mailing list unfriendly.
The documentation at http://wiki2.dovecot.org/MailboxFormat/Maildir suggests that file system level issues are mostly about performance.
This note seems aprops:
"Locking
"Although maildir was designed to be lockless, Dovecot locks the maildir while doing modifications to it or while looking for new messages in it. This is required because otherwise Dovecot might temporarily see mails incorrectly deleted, which would cause trouble. Basically the problem is that if one process modifies the maildir (eg. a rename() to change a message's flag), another process in the middle of listing files at the same time could skip a file. The skipping happens because readdir() system call doesn't guarantee that all the files are returned if the directory is modified between the calls to it. This problem exists with all the commonly used filesystems.
"Because Dovecot uses its own non-standard locking (dovecot-uidlist.lock dotlock file), other MUAs accessing the maildir don't support it. This means that if another MUA is updating messages' flags or expunging messages, Dovecot might temporarily lose some message. After the next sync when it finds it again, *an error message may be written to log and the message will receive a new UID.*
"Delivering mails to new/ directory doesn't have any problems, so there's no need for LDAs to support any type of locking."
(emphasis added)
Certainly flags are not being set on 1000's of messages at a time and while I tend to suspect Thunderbird of doing things that are flaky or out of spec in an attempt to be clever and efficient, Mulberry tends to be painfully strictly adherent to specification.
dovecot.log shows runs of this error: Apr 15 09:02:37 imap(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306286, file=1429102024.M826331P1156.host,S=1678,W=1724:2,S)
Such message I saw only, when I manually changed files in the Maildir directory. That's why I pointed out ZFS above. Do you use some strategies, that freezes a Maildir, then do something (e.g. backup), then thaw the Maildir. During the backup, a client could delete a message, which reapper after thaw.
Understood and agreed - it seems like some process is moving things around, but there's no file-system level indication that is happening. In fact, watching the logs live, these messages flood the log whenever a message is sent (sending this message will trigger an avalanche of "expunged message reappeared" messages, for example).
Other possibilities: rsync/copy, vi, ... on file system level When you operate on filesystem level on the Maildirs keep in mind, that filenames store message flags and status, which may change regularily.
I do nightly RSYNC backups to a FreeNAS server from the host (mail runs from a freebsd jail), but the updates are far, far more frequent than those daily backups.
I've set mbox_dirty_syncs = no mbox_lazy_writes = no
you are using Maildir, no? They don't effect Maildir.
mail_location = maildir:~:CONTROL=/var/no-quota/%u
this one hits me:
http://wiki2.dovecot.org/VirtualUsers/Home "Home directory shouldn't be the same as mail directory. It's possible to do that, but you might run into trouble with it sooner or later. Some problems with this are: " ...
That makes sense, but this directory structure does not put the mail in the user's home directory. It is a directory that nothing but the mail system touches (normally, unless I'm poking around looking for problems). The home directories are in their usual places: /usr/home/user... and have no (active) Maildir.
Mail is under an entirely separate root level directory: /mail/domain.tld/user...
mail_plugins = quota mail_log notify fts fts_lucene
I don't run FTS, where does lucene store its files? In the user's home?
Within the maildir, so the FTS_lucene indicies are at
/mail/domain.tld/user/lucene-indexes/_8u.cfs /mail/domain.tld/user/lucene-indexes/segements.gen /mail/domain.tld/user/lucene-indexes/segements_hr
Frankly, FTS is a little disappointing. Stand-alone clients don't support server-side search well, in particular they seem to limit search to the active folder rather than searching across the entire mailbox. The premise of FTS for me was to enable particularly mobile devices (=K9/Android) to have search access to the entire mailbox and all archives in some relatively expedient fashion since there are not yet uSD cards large enough to store all that mail. But no... it doesn't really seem to work that way. You can find a message within the currently active folder quickly, but you can do that without server-side search anyway.
Mulberry does a pretty amazing job of this, however. You can watch it blast through directories that have FTS indexing one after another.
Apr 15 13:17:26 indexer-worker(user@domain.com): user-lookup(user@domain.com)Debug: Added userdb setting: mail=maildir:~/ Apr 15 13:17:26 indexer-worker(user@domain.com): user-lookup(user@domain.com)Debug: Added userdb setting: plugin/quota_rule=*:bytes=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Effective uid=5000, gid=5000, home=/mail/domain.com/user/ Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=0 messages=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=0 (30%) messages=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=0 (30%) messages=0 Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota warning: bytes=0 (90%) messages=0 reverse=no command=quota-warning 90 user@domain.com Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota warning: bytes=0 (75%) messages=0 reverse=no command=quota-warning 75 user@domain.com Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Quota grace: root=User quota bytes=0 (10%) Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/ Apr 15 13:17:26 indexer-worker(user@domain.com): Debug: maildir++: root=/mail/domain.com/user/, index=, indexpvt=, control=, inbox=/mail/domain.com/user/, alt= Apr 15 13:17:27 indexer-worker(user@domain.com): Debug: Ignoring unknown cache field: pop3.order Apr 15 13:17:27 indexer-worker(user@domain.com): Debug: Ignoring unknown cache field: binary.parts Apr 15 13:17:27 indexer-worker(user@domain.com): Debug: Ignoring unknown cache field: body.snippet
Apr 15 13:44:25 lda(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:44:25 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=53687091200 messages=0 Apr 15 13:44:25 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=+16106127360 (30%) messages=0 Apr 15 13:44:25 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=+16106127360 (30%) messages=0 Apr 15 13:44:25 lda(user@domain.com): Debug: Quota warning: bytes=48318382080 (90%) messages=0 reverse=no command=quota-warning 90 raw mail user Apr 15 13:44:25 lda(user@domain.com): Debug: Quota warning: bytes=40265318400 (75%) messages=0 reverse=no command=quota-warning 75 raw mail user Apr 15 13:44:25 lda(user@domain.com): Debug: Quota grace: root=User quota bytes=5368709120 (10%) Apr 15 13:44:25 lda(user@domain.com): Debug: none: root=, index=, indexpvt=, control=, inbox=, alt= Apr 15 13:49:32 lda(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:49:32 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=53687091200 messages=0 Apr 15 13:49:32 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=+16106127360 (30%) messages=0 Apr 15 13:49:32 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=+16106127360 (30%) messages=0 Apr 15 13:49:32 lda(user@domain.com): Debug: Quota warning: bytes=48318382080 (90%) messages=0 reverse=no command=quota-warning 90 raw mail user Apr 15 13:49:32 lda(user@domain.com): Debug: Quota warning: bytes=40265318400 (75%) messages=0 reverse=no command=quota-warning 75 raw mail user Apr 15 13:49:32 lda(user@domain.com): Debug: Quota grace: root=User quota bytes=5368709120 (10%) Apr 15 13:49:32 lda(user@domain.com): Debug: none: root=, index=, indexpvt=, control=, inbox=, alt= Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file storage: Using script storage path: /mail/domain.com/user//sieve Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file storage: Relative path to sieve storage in active link: sieve/ Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened script
Forwards' from/mail/domain.com/user/sieve/Forwards.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Server_Msg' from/mail/domain.com/user/sieve/File_Server_Msg.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_SRL' from/mail/domain.com/user/sieve/File_SRL.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_BULK' from/mail/domain.com/user/sieve/File_BULK.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Commerce' from/mail/domain.com/user/sieve/File_Commerce.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Impersonal' from/mail/domain.com/user/sieve/File_Impersonal.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Travel' from/mail/domain.com/user/sieve/File_Travel.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Tribe' from/mail/domain.com/user/sieve/File_Tribe.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Info' from/mail/domain.com/user/sieve/File_Info.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Lists' from/mail/domain.com/user/sieve/File_Lists.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Trash' from/mail/domain.com/user/sieve/File_Trash.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Security' from/mail/domain.com/user/sieve/File_Security.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Notifications' from/mail/domain.com/user/sieve/File_Notifications.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: file script: Opened scriptFile_Spam' from/mail/domain.com/user/sieve/File_Spam.sieve' Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: Script binary /mail/domain.com/user/.dovecot.svbin successfully loaded Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: binary save: not saving binary /mail/domain.com/user/.dovecot.svbin, because it is already stored Apr 15 13:49:41 lda(user@domain.com): Debug: sieve: Executing script from `/mail/domain.com/user/.dovecot.svbin' Apr 15 13:49:41 lda(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:49:41 lda(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=53687091200 messages=0Apr 15 13:30:31 imap(user@domain.com): Debug: Loading modules from directory: /usr/local/lib/dovecot Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib10_quota_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib11_imap_quota_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib15_notify_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib20_fts_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib20_mail_log_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Module loaded: /usr/local/lib/dovecot/lib21_fts_lucene_plugin.so Apr 15 13:30:31 imap(user@domain.com): Debug: Added userdb setting: plugin/quota_rule=*:bytes=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Effective uid=5000, gid=5000, home=/mail/domain.com/user/ Apr 15 13:30:31 imap(user@domain.com): Debug: Quota root: name=User quota backend=maildir args= Apr 15 13:30:31 imap(user@domain.com): Debug: Quota rule: root=User quota mailbox=* bytes=0 messages=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Quota rule: root=User quota mailbox=Trash bytes=0 (30%) messages=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Quota rule: root=User quota mailbox=Sent bytes=0 (30%) messages=0 Apr 15 13:30:31 imap(user@domain.com): Debug: Quota warning: bytes=0 (90%) messages=0 reverse=no command=quota-warning 90 user@domain.com Apr 15 13:30:31 imap(user@domain.com): Debug: Quota warning: bytes=0 (75%) messages=0 reverse=no command=quota-warning 75 user@domain.com Apr 15 13:30:31 imap(user@domain.com): Debug: Quota grace: root=User quota bytes=0 (10%) Apr 15 13:30:31 imap(user@domain.com): Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~:CONTROL=/var/no-quota/user@domain.com Apr 15 13:30:31 imap(user@domain.com): Debug: maildir++: root=/mail/domain.com/user/, index=, indexpvt=, control=/var/no-quota/user@domain.com, inbox=/mail/domain.com/user/, alt=
- -- Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1
iQEVAwUBVS9dNnz1H7kL/d9rAQLn8Af/cQ8BSg6cmUFj6qGVcQUglJkI8hjY3CQM 2MBI/qQbouo4hg3eQNOLX+MOYAGcCV2I+wM8WkOJkqOjPn8vBZACHe5Y860mBbEA XipvGMML1DJt+4leNo/1jPpiFJEFZ3w9kFiCC+rPcjrTU8XV5g+l9RQDofu8vElZ jySGQvH3Ml7kP2afTrqiBb3cwoQVLXMYUTsjw4csw0qn3lWB7i3yN/WACsBMFBP6 H0KnM99UUYbOJ4TMsBJ7aDXIUIvlu6Eo1oGznIsKiX1k6BoCPQtXwlxk4NJ6f8B/ SaGYf6FPSQmKaePTVwxJfSc8sTBxb+rG7DsZQnGjwZFtGH3ti810eg== =6hFs -----END PGP SIGNATURE-----
On 16 Apr 2015, at 04:45, David Gessel gessel@blackrosetech.com wrote:
My Dovecot 2.2.16 server is interacting poorly with a variety of mail clients. The symptoms include disappearing messages, mismatched summaries, duplicated messages, and excessive full re-downloads.
What were you running before Dovecot v2.2.16? An earlier Dovecot? A whole different system?
dovecot.log shows runs of this error: Apr 15 09:02:37 imap(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306286, file=1429102024.M826331P1156.host,S=1678,W=1724:2,S)
or this error: Apr 15 10:04:00 indexer-worker(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306803, file=1428785463.M645546P27215.host,S=5389,W=5442:2,S) .. The first entry in dovecot.log.0 is at Apr 15 10:00:12, and the last entry at Apr 15 12:00:13; Dovecot is logging 4,490 expunged message reappeared messages per hour. Note the server has 4 accounts set up and very limited traffic, so 4,490 per hour would seem like a lot of anything to be logged.
These really shouldn't be happening..
Hi Timo,
Thank you for the reply. It is very much appreciated.
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Thu Apr 16 2015 21:31:30 GMT+0300 (Arabic Standard Time)
On 16 Apr 2015, at 04:45, David Gessel gessel@blackrosetech.com wrote:
My Dovecot 2.2.16 server is interacting poorly with a variety of mail clients. The symptoms include disappearing messages, mismatched summaries, duplicated messages, and excessive full re-downloads.
What were you running before Dovecot v2.2.16? An earlier Dovecot? A whole different system?
I migrated from Cyrus to Dovecot in July of last year on version 2.2.13. The issues started then and haven't really ever mitigated, though my impression (without any real data to back it up) is that it is more of a problem now, particularly mail appear/disappear issues. The first issue I noticed was unexpectedly frequent full resyncs in TB.
dovecot.log shows runs of this error: Apr 15 09:02:37 imap(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306286, file=1429102024.M826331P1156.host,S=1678,W=1724:2,S)
or this error: Apr 15 10:04:00 indexer-worker(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306803, file=1428785463.M645546P27215.host,S=5389,W=5442:2,S) .. The first entry in dovecot.log.0 is at Apr 15 10:00:12, and the last entry at Apr 15 12:00:13; Dovecot is logging 4,490 expunged message reappeared messages per hour. Note the server has 4 accounts set up and very limited traffic, so 4,490 per hour would seem like a lot of anything to be logged.
These really shouldn't be happening..
I didn't think so. I've contemplated migrating to sdbox, but Maildir shouldn't be a problem, I don't think. Things that strike me as possibly moving my config out of the well-tested regime include (not that anything is unique, but there may not be that many people testing all of the following):
FreeBSD 10.1 ZFS mail_location = maildir:~/:CONTROL=/var/no-quota/%u FTS-Lucene Sieve/lmtp Quota
Not that anything looks suspicious. The logs don't seem to indicate any reason for the "Expunged message reappeared, giving a new UID" errors. Is there someplace else the cause might be logged?
scanning the logs for occurrences of "error," I find:
# grep error dovecot* dovecot-info.log:Apr 15 17:01:09 lda(user1@domain1.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=, size=5887 dovecot-info.log:Apr 16 03:06:48 lda(user1@domain1.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=20150416100642.CA9C824764@host2.localdomain, size=13237 dovecot-info.log:Apr 16 17:01:18 lda(user1@domain1.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=, size=5887 dovecot-info.log.0:Apr 14 13:24:07 lda(user1@domain1.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=CAFOe2y4AwkM_BnkGNssLKkXRFJRk1GoAo7y6T7igTwtFMQk28Q@mail.gmail.tld, size=3033 dovecot-info.log.0:Apr 14 13:24:07 lda(user1@domain1.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=cf8d60100fb6d439c559221f00df2f37f80.20150414175622@mail100.atl31.mcdlv.net, size=32589 dovecot-info.log.0:Apr 14 13:24:07 lda(user2@domain2.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=23233383_24761373-24761373@sbe203.redbeanforhealthopen.ninja, size=6951 dovecot-info.log.0:Apr 14 13:24:07 lda(user1@domain1.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=<93B38E8FD4B2741936862E3F@[10.0.248.3]>, size=2197 dovecot-info.log.0:Apr 14 13:24:07 lda(user1@domain1.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=<4A13BE2E2FC7C49B7112BEE5@[10.0.248.3]>, size=4700 dovecot-info.log.0:Apr 14 13:29:07 lda(user2@domain2.tld): Info: copy from stdin: box=INBOX, uid=952044, msgid=2361227557511242361114254436978565@ddxlohivv.errorsinvolved.tld, size=6891 dovecot-info.log.0:Apr 14 13:34:07 lda(user1@domain1.tld): Info: copy from stdin: box=Bulkmail, uid=error, msgid=<1120736677264.1115884694416.1417834012.0.291256JL.1002@scheduler.constantcon..., size=44835 dovecot-info.log.0:Apr 14 13:34:07 lda(user1@domain1.tld): Info: copy from stdin: box=Bulkmail, uid=error, msgid=cm.050532.qulthjk.jyntyklj.r@cmail20.tld, size=42787 dovecot-info.log.0:Apr 14 13:34:07 lda(user2@domain2.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=63b529fb59de3613763afced1552234b_4334516_4774565@sbe213.proslimfitbody.ninja, size=4407 dovecot-info.log.0:Apr 14 13:39:07 lda(user1@domain1.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=cec4d3a3384c6e714e89d33d4a113800-m511477@pfsense.org, size=2941 dovecot-info.log.0:Apr 14 13:59:07 lda(user2@domain2.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=<22304076-63b529fb59de3613763afced1552234b.63b529fb59de3613763afced1552234b@s..., size=4492 dovecot-info.log.0:Apr 14 17:01:08 lda(user1@domain1.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=, size=5887 dovecot-info.log.0:Apr 15 17:00:09 lda(user3@domain1.tld): Info: copy from stdin: box=INBOX, uid=error, msgid=201504160000.t3G005Eu034535@brunch.is, size=1762 dovecot.log.9:Apr 15 11:02:42 imap(user1@domain1.tld): Error: Log synchronization error at seq=3274,offset=152 for /mail/domain1.tld/user1//dovecot.index: Append with UID 302382, but next_uid = 2419524
Not a lot of errors, but not zero either.
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Thu Apr 16 2015 21:31:30 GMT+0300 (Arabic Standard Time)
On 16 Apr 2015, at 04:45, David Gessel gessel@blackrosetech.com wrote:
My Dovecot 2.2.16 server is interacting poorly with a variety of mail clients. The symptoms include disappearing messages, mismatched summaries, duplicated messages, and excessive full re-downloads.
What were you running before Dovecot v2.2.16? An earlier Dovecot? A whole different system?
dovecot.log shows runs of this error: Apr 15 09:02:37 imap(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306286, file=1429102024.M826331P1156.host,S=1678,W=1724:2,S)
or this error: Apr 15 10:04:00 indexer-worker(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306803, file=1428785463.M645546P27215.host,S=5389,W=5442:2,S) .. The first entry in dovecot.log.0 is at Apr 15 10:00:12, and the last entry at Apr 15 12:00:13; Dovecot is logging 4,490 expunged message reappeared messages per hour. Note the server has 4 accounts set up and very limited traffic, so 4,490 per hour would seem like a lot of anything to be logged.
These really shouldn't be happening..
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Thu Apr 16 2015 21:31:30 GMT+0300 (Arabic Standard Time)
On 16 Apr 2015, at 04:45, David Gessel gessel@blackrosetech.com wrote:
My Dovecot 2.2.16 server is interacting poorly with a variety of mail clients. The symptoms include disappearing messages, mismatched summaries, duplicated messages, and excessive full re-downloads.
What were you running before Dovecot v2.2.16? An earlier Dovecot? A whole different system?
dovecot.log shows runs of this error: Apr 15 09:02:37 imap(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306286, file=1429102024.M826331P1156.host,S=1678,W=1724:2,S)
or this error: Apr 15 10:04:00 indexer-worker(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306803, file=1428785463.M645546P27215.host,S=5389,W=5442:2,S) .. The first entry in dovecot.log.0 is at Apr 15 10:00:12, and the last entry at Apr 15 12:00:13; Dovecot is logging 4,490 expunged message reappeared messages per hour. Note the server has 4 accounts set up and very limited traffic, so 4,490 per hour would seem like a lot of anything to be logged.
These really shouldn't be happening..
One possibility is that there is a scrub/verify routine running that is checking the actual size vs. reported size of messages, and perhaps that routine doesn't know about ZFS compression:
zroot/ezjail used 117G - zroot/ezjail compressratio 1.25x - zroot/ezjail compression lz4 local zroot/ezjail logicalused 137G -
and is seeing something anomalous and trying to "fix" that, triggering a rescan. A long shot and seems unlikely, but I have no other ideas.
I also note from the documentation on the wiki:
"Because Dovecot uses its own non-standard locking (dovecot-uidlist.lock dotlock file), other MUAs accessing the maildir don't support it. This means that if another MUA is updating messages' flags or expunging messages, Dovecot might temporarily lose some message. After the next sync when it finds it again, an error message may be written to log and the message will receive a new UID. "
...which are the right symptoms, but seems unlikely to be the right cause.
And that:
"Maildir format is somewhat compatible with MH format. This is sometimes a problem when people configure their procmail to deliver mails to Maildir/new. This makes procmail create the messages in MH format, which basically means that the file is called msg.inode_number. While this appears to work first, after expunging messages from the maildir the inodes are freed and will be reused later. This means that another file with the same name may come to the maildir, which makes Dovecot think that an expunged file reappeared into the mailbox and an error is logged. "
...which is exactly the error, but the
And since I'm using Dovecot LMTP/LDA, it seems odd that errors would be generated.
My main.cf config includes:
virtual_transport = dovecot dovecot_destination_recipient_limit = 1 home_mailbox = Maildir/ mail_spool_directory = /mail mailbox_command = /usr/local/libexec/dovecot/deliver mailbox_transport = dovecot
On 18 Apr 2015, at 15:02, David Gessel gessel@blackrosetech.com wrote:
dovecot.log shows runs of this error: Apr 15 09:02:37 imap(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306286, file=1429102024.M826331P1156.host,S=1678,W=1724:2,S)
or this error: Apr 15 10:04:00 indexer-worker(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306803, file=1428785463.M645546P27215.host,S=5389,W=5442:2,S)
One possibility is that there is a scrub/verify routine running that is checking the actual size vs. reported size of messages, and perhaps that routine doesn't know about ZFS compression:
zroot/ezjail used 117G - zroot/ezjail compressratio 1.25x - zroot/ezjail compression lz4 local zroot/ezjail logicalused 137G -
and is seeing something anomalous and trying to "fix" that, triggering a rescan. A long shot and seems unlikely, but I have no other ideas.
No. My best guess is that (your) ZFS+FreeBSD is simply not behaving the way Dovecot wants filesystems to behave (readdir() sometimes skipping over files). I don't have any other suggestion than trying a different filesystem or OS. I haven't heard ZFS having these problems before though.
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 15:48:28 GMT+0300 (Arabic Standard Time)
No. My best guess is that (your) ZFS+FreeBSD is simply not behaving the way Dovecot wants filesystems to behave (readdir() sometimes skipping over files). I don't have any other suggestion than trying a different filesystem or OS. I haven't heard ZFS having these problems before though.
Or migrating to sdbox. Absent any further suggestions, that will be my next step. My commitment to Maildir is far lower than my commitment to FreeBSD/ZFS. It is just a historical preference coming from a decade+ of courier IMAP.
On Apr 18, 2015, at 8:00 AM, David Gessel wrote:
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 15:48:28 GMT+0300 (Arabic Standard Time)
No. My best guess is that (your) ZFS+FreeBSD is simply not behaving the way Dovecot wants filesystems to behave (readdir() sometimes skipping over files). I don't have any other suggestion than trying a different filesystem or OS. I haven't heard ZFS having these problems before though.
Or migrating to sdbox. Absent any further suggestions, that will be my next step. My commitment to Maildir is far lower than my commitment to FreeBSD/ZFS. It is just a historical preference coming from a decade+ of courier IMAP.
What is the output for:
# zpool status
perhaps you have a hardware issue?
Edgar, thanks for the help!
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Edgar Pettijohn III edgar@pettijohn-web.com To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 16:30:07 GMT+0300 (Arabic Standard Time)
On Apr 18, 2015, at 8:00 AM, David Gessel wrote:
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 15:48:28 GMT+0300 (Arabic Standard Time)
No. My best guess is that (your) ZFS+FreeBSD is simply not behaving the way Dovecot wants filesystems to behave (readdir() sometimes skipping over files). I don't have any other suggestion than trying a different filesystem or OS. I haven't heard ZFS having these problems before though.
Or migrating to sdbox. Absent any further suggestions, that will be my next step. My commitment to Maildir is far lower than my commitment to FreeBSD/ZFS. It is just a historical preference coming from a decade+ of courier IMAP.
What is the output for:
# zpool status
perhaps you have a hardware issue?
All good - quite reliable hardware: IBM x3655 dual AMD quad core, 40GB of ECC RAM, 8x IBM 2.5" SAS on battery-backed ServeRAID, RAID 6 and (somewhat pointlessly) ZFS2. All IBM server diagnostics check, full RAM check run without errors, no ECC corrections reported, no uncorrectable errors reported.
# zpool status pool: bootpool state: ONLINE scan: none requested config:
NAME STATE READ WRITE CKSUM
bootpool ONLINE 0 0 0
aacd0s1a ONLINE 0 0 0errors: No known data errors
pool: zroot state: ONLINE scan: none requested config:
NAME STATE READ WRITE CKSUM
zroot ONLINE 0 0 0
aacd0s1d.eli ONLINE 0 0 0errors: No known data errors
On Apr 18, 2015, at 9:09 AM, David Gessel wrote:
Edgar, thanks for the help!
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Edgar Pettijohn III edgar@pettijohn-web.com To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 16:30:07 GMT+0300 (Arabic Standard Time)
On Apr 18, 2015, at 8:00 AM, David Gessel wrote:
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 15:48:28 GMT+0300 (Arabic Standard Time)
No. My best guess is that (your) ZFS+FreeBSD is simply not behaving the way Dovecot wants filesystems to behave (readdir() sometimes skipping over files). I don't have any other suggestion than trying a different filesystem or OS. I haven't heard ZFS having these problems before though.
Or migrating to sdbox. Absent any further suggestions, that will be my next step. My commitment to Maildir is far lower than my commitment to FreeBSD/ZFS. It is just a historical preference coming from a decade+ of courier IMAP.
What is the output for:
# zpool status
perhaps you have a hardware issue?
All good - quite reliable hardware: IBM x3655 dual AMD quad core, 40GB of ECC RAM, 8x IBM 2.5" SAS on battery-backed ServeRAID, RAID 6 and (somewhat pointlessly) ZFS2. All IBM server diagnostics check, full RAM check run without errors, no ECC corrections reported, no uncorrectable errors reported.
# zpool status pool: bootpool state: ONLINE scan: none requested config:
NAME STATE READ WRITE CKSUM bootpool ONLINE 0 0 0 aacd0s1a ONLINE 0 0 0errors: No known data errors
pool: zroot state: ONLINE scan: none requested config:
NAME STATE READ WRITE CKSUM zroot ONLINE 0 0 0 aacd0s1d.eli ONLINE 0 0 0errors: No known data errors
are you using compression? If so which.
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Edgar Pettijohn III edgar@pettijohn-web.com To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 17:20:30 GMT+0300 (Arabic Standard Time)
On Apr 18, 2015, at 9:09 AM, David Gessel wrote:
Edgar, thanks for the help!
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Edgar Pettijohn III edgar@pettijohn-web.com To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 16:30:07 GMT+0300 (Arabic Standard Time)
On Apr 18, 2015, at 8:00 AM, David Gessel wrote:
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 15:48:28 GMT+0300 (Arabic Standard Time)
No. My best guess is that (your) ZFS+FreeBSD is simply not behaving the way Dovecot wants filesystems to behave (readdir() sometimes skipping over files). I don't have any other suggestion than trying a different filesystem or OS. I haven't heard ZFS having these problems before though.
Or migrating to sdbox. Absent any further suggestions, that will be my next step. My commitment to Maildir is far lower than my commitment to FreeBSD/ZFS. It is just a historical preference coming from a decade+ of courier IMAP.
What is the output for:
# zpool status
perhaps you have a hardware issue?
All good - quite reliable hardware: IBM x3655 dual AMD quad core, 40GB of ECC RAM, 8x IBM 2.5" SAS on battery-backed ServeRAID, RAID 6 and (somewhat pointlessly) ZFS2. All IBM server diagnostics check, full RAM check run without errors, no ECC corrections reported, no uncorrectable errors reported.
# zpool status pool: bootpool state: ONLINE scan: none requested config:
NAME STATE READ WRITE CKSUM bootpool ONLINE 0 0 0 aacd0s1a ONLINE 0 0 0errors: No known data errors
pool: zroot state: ONLINE scan: none requested config:
NAME STATE READ WRITE CKSUM zroot ONLINE 0 0 0 aacd0s1d.eli ONLINE 0 0 0errors: No known data errors
are you using compression? If so which.
Yes, lz4.
On 18 Apr 2015, at 16:00, David Gessel gessel@blackrosetech.com wrote:
No. My best guess is that (your) ZFS+FreeBSD is simply not behaving the way Dovecot wants filesystems to behave (readdir() sometimes skipping over files). I don't have any other suggestion than trying a different filesystem or OS. I haven't heard ZFS having these problems before though.
Or migrating to sdbox. Absent any further suggestions, that will be my next step. My commitment to Maildir is far lower than my commitment to FreeBSD/ZFS. It is just a historical preference coming from a decade+ of courier IMAP.
Actually as a workaround you could try maildir_very_dirty_syncs=yes which gets rid of most of the readdir()s.
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 17:38:02 GMT+0300 (Arabic Standard Time)
Actually as a workaround you could try maildir_very_dirty_syncs=yes which gets rid of most of the readdir()s.
Enabled.
I can't read that option without hearing Bubbles say it.
Might this also help: maildir_broken_filename_sizes = yes
I was a little suspicious of sizes and had considered running your maildir-size-fix.pl script. They did come from Courier and after 10 years or more of operation, the risk of cruftiness is high. However, I thought it was a long shot as I IMAP-Synced to the new directory so the directory was built by dovecot... right? I mean it wasn't a # mv operation.
-David
THANKS TIMO!
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 17:38:02 GMT+0300 (Arabic Standard Time)
Actually as a workaround you could try maildir_very_dirty_syncs=yes which gets rid of most of the readdir()s.
I will try that right now and report any differences in behavior!
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: David Gessel gessel@blackrosetech.com To: Timo Sirainen tss@iki.fi Date: Sat Apr 18 2015 20:35:40 GMT+0300 (Arabic Standard Time)
THANKS TIMO!
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 17:38:02 GMT+0300 (Arabic Standard Time)
Actually as a workaround you could try maildir_very_dirty_syncs=yes which gets rid of most of the readdir()s.
I will try that right now and report any differences in behavior!
Alas, it hasn't solved the problem - still getting duplicate messages in thunderbird. So far it appears that mulberry is a little happier, but I find some messages are missing - such as the archive of the dovecot mailing list jumping from 2015-03-21 to 2015-04-14.
I tried # rm -r dovecot.id*
Would "maildir_broken_filename_sizes = yes" have any impact? If it does, then I'd think your fix sizes script would be worth a try.
If all that fails - is there any reason to think that sdbox will be better behaved?
-David
Since you have confirmed that someone else you know is using it on FreeBSD+ZFS without these problems, have you tried asking on the FreeBSD support list(s)?
Seems like that may be your best bet, since it is certainly not a generic dovecot problem (but may indeed be one or more of the settings you are using)...
You could also go ahead and post the diff of your config and your friends (I'm fairly sure this list is small attachment friendly, but I recommend pasted it in the email body anyway) and see if anything jumps out at anyone/Timo...
On 4/18/2015 10:34 PM, David Gessel gessel@blackrosetech.com wrote:
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: David Gessel gessel@blackrosetech.com To: Timo Sirainen tss@iki.fi Date: Sat Apr 18 2015 20:35:40 GMT+0300 (Arabic Standard Time)
THANKS TIMO!
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 17:38:02 GMT+0300 (Arabic Standard Time)
Actually as a workaround you could try maildir_very_dirty_syncs=yes which gets rid of most of the readdir()s. I will try that right now and report any differences in behavior!
Alas, it hasn't solved the problem - still getting duplicate messages in thunderbird. So far it appears that mulberry is a little happier, but I find some messages are missing - such as the archive of the dovecot mailing list jumping from 2015-03-21 to 2015-04-14.
I tried # rm -r dovecot.id*
Would "maildir_broken_filename_sizes = yes" have any impact? If it does, then I'd think your fix sizes script would be worth a try.
If all that fails - is there any reason to think that sdbox will be better behaved?
-David
Charles,
Thank you for your kind offer. I've sent a message with both the standard diff and an HTML attachment comparison that I find a lot easier to read. It awaits moderator approval due to size.
-David
very_dirty_syncs helped a lot - the problems still happen but only about every 30 minutes. It seems this flag prevents re-indexing on whatever was constantly inducing it (with every client-check, if there was a change written to the directory, is my best guess watching the logs go).
I still get all the same symptoms, but far less frequently.
I'm inclined to believe, as trivial as it may be to enumerate, that:
Something is triggering dovecot to believe the indexes need to be rebuilt.
When checking mail during the rebuild, clients get confused by UIDs in transition.
Today I had to quit TB and restart because duplicates filled my preview pane. Mulberry has been better, when it gets confused now, it is usually sufficient to initiate a manual check or expunge to get the list to update.
I would think that sdbox would alleviate these issues, no?
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 17:38:02 GMT+0300 (Arabic Standard Time)
On 18 Apr 2015, at 16:00, David Gessel gessel@blackrosetech.com wrote:
No. My best guess is that (your) ZFS+FreeBSD is simply not behaving the way Dovecot wants filesystems to behave (readdir() sometimes skipping over files). I don't have any other suggestion than trying a different filesystem or OS. I haven't heard ZFS having these problems before though.
Or migrating to sdbox. Absent any further suggestions, that will be my next step. My commitment to Maildir is far lower than my commitment to FreeBSD/ZFS. It is just a historical preference coming from a decade+ of courier IMAP.
Actually as a workaround you could try maildir_very_dirty_syncs=yes which gets rid of most of the readdir()s.
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
On Thu, 23 Apr 2015, David Gessel wrote:
I'm inclined to believe, as trivial as it may be to enumerate, that:
Something is triggering dovecot to believe the indexes need to be rebuilt. When checking mail during the rebuild, clients get confused by UIDs in transition.
I would think that sdbox would alleviate these issues, no?
The real problem is that you do not know _why_ "Something is triggering dovecot to believe the indexes need to be rebuilt".
This is the same for sdbox and mdbox, IMHO.
That's why I asked about if some external process is trying to change the mail storage. Is there something except Dovecot that changes the mtime of the directories "new", "cur" or Maildir base? Do you deliver messages without Dovecot LDA/LMTP? Do you store different information in the Maildir? Do you (not) have separate mail storage and user home directories? Do you run a virus checker on file system level?
Do you run two Dovecot instances on the same server, maybe as left over from some testing or crash?
Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1
iQEVAwUBVTnw6nz1H7kL/d9rAQKz+AgAuD0pyVOSQILqA6kLYgGOcUU0Wa8ca91H 3UB2t18AxVXx3/elCguTdNFpd0AB2dMfjkWaob/9ywr60i8wjNIZPQcWAI4hmeoV 2YHm+YJ8ndfSdYKQ6mN34mDBmD1+K69h8v5GVfQ5jOakcwPSqemBWY8RjfLtmSpU wgfRZtkG209BZxaAi3fj2J6xrpgE4BYG0g3KwafVRGLZMcBFujO0UJgPqeMmEMJY NwSgSgRoU1Aau+nTQGYrFzsSgtuG8R2LnF2l4nYWTL12PAiiqgbuAQCQ/WXf3jzQ OWtzcKM7laO9nc5iXuaAiO59TrV9VtevcTrE8usK2FdJke2C2bEVWw== =3KjE -----END PGP SIGNATURE-----
Steffen,
I apologize for missing your helpful message - I wasn't intentionally ignoring it. One of the artifacts of my mail issues is that mail disappears, this included.
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Steffen Kaiser skdovecot@smail.inf.fh-brs.de To: David Gessel gessel@blackrosetech.com Date: Fri Apr 24 2015 10:29:46 GMT+0300 (Arabic Standard Time)
On Thu, 23 Apr 2015, David Gessel wrote:
I'm inclined to believe, as trivial as it may be to enumerate, that:
Something is triggering dovecot to believe the indexes need to be rebuilt. When checking mail during the rebuild, clients get confused by UIDs in transition.
I would think that sdbox would alleviate these issues, no?
The real problem is that you do not know _why_ "Something is triggering dovecot to believe the indexes need to be rebuilt".
I'm not 100% sure that's what is happening.
This is the same for sdbox and mdbox, IMHO.
that would be sad - but I haven't tried that yet.
That's why I asked about if some external process is trying to change the mail storage. Is there something except Dovecot that changes the mtime of the directories "new", "cur" or Maildir base?
Not that I am aware of. this is a jail only running mail.
Do you deliver messages without Dovecot LDA/LMTP?
Dovecot LDA only.
Do you store different information in the Maildir?
nothing not part of Dovecot's processes - but the full text index files are also stored there.
Do you (not) have separate mail storage and user home directories?
Virtual mail configuration - home directories are completely isolated. Nothing happens in /mail that isn't mail related.
Do you run a virus checker on file system level?
no, but amavisd calls clamAV on inbound messages.
Do you run two Dovecot instances on the same server, maybe as left over from some testing or crash?
certainly not intentionally and I'm pretty confident not actually; these issues survive many reboots without much variation, so not from testing.
-- Steffen Kaiser
Some updates to the process:
I experimented with all variations of Mail processes values with no real improvement - some perhaps but likely as not just observational variations rather than meaningful data. Specifically in 10-mail.conf: mmap_disable = yes mail_fsync = always lock_method = flock
I'm probably suffering from confirmation bias, but I think things got a little bit better.
However, I still got double messages in TB and K9 on some checks. Then I looked at the IMAP capability string returned from telnet localhost 993. It didn't include NAMESPACE. The post-login enumeration did, but not the pre-login.
adding imap_capability = +NAMESPACE to 20-imap.conf seems to have cleared up the appearance of double entries in clients. I had one message's header/display get confused (another symptom of the issues) but given the problems my local client database is pretty scrambled. when I have a decent network connection for a few days, I'll try recreating my client database and see if that helps.
The update to dovecot2-2.2.18/dovecot-pigeonhole-0.4.8 seems to have made problems worse. Whole directories don't load at all - or they may load a weird segment - like mail from a few months ago back and mail from the last two days, but nothing in between.
I did a # find /mail -name "dovecot.index*" -type f -delete
and then on the client side (K9) things clear up, on TB a Right click on folder -> properties -> repair folder cleans things up. Of course all messages have to be redownloaded so it isn't exactly a performant option.
Is there a way to completely disable caching on dovecot? I know it is sort of the raison d'être, but if I can't solve the problems with dovecot, I'll have to try a different, non-caching/indexing server anyway and at least it would help narrow down the issues.
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: David Gessel gessel@blackrosetech.com To: Timo Sirainen tss@iki.fi Date: Thu Apr 23 2015 18:39:02 GMT+0400 (Arabian Standard Time)
very_dirty_syncs helped a lot - the problems still happen but only about every 30 minutes. It seems this flag prevents re-indexing on whatever was constantly inducing it (with every client-check, if there was a change written to the directory, is my best guess watching the logs go).
I still get all the same symptoms, but far less frequently.
I'm inclined to believe, as trivial as it may be to enumerate, that:
Something is triggering dovecot to believe the indexes need to be rebuilt.
When checking mail during the rebuild, clients get confused by UIDs in transition.
Today I had to quit TB and restart because duplicates filled my preview pane. Mulberry has been better, when it gets confused now, it is usually sufficient to initiate a manual check or expunge to get the list to update.
I would think that sdbox would alleviate these issues, no?
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Sat Apr 18 2015 17:38:02 GMT+0300 (Arabic Standard Time)
On 18 Apr 2015, at 16:00, David Gessel gessel@blackrosetech.com wrote:
No. My best guess is that (your) ZFS+FreeBSD is simply not behaving the way Dovecot wants filesystems to behave (readdir() sometimes skipping over files). I don't have any other suggestion than trying a different filesystem or OS. I haven't heard ZFS having these problems before though.
Or migrating to sdbox. Absent any further suggestions, that will be my next step. My commitment to Maildir is far lower than my commitment to FreeBSD/ZFS. It is just a historical preference coming from a decade+ of courier IMAP.
Actually as a workaround you could try maildir_very_dirty_syncs=yes which gets rid of most of the readdir()s.
Il 20/05/2015 10:44, David Gessel ha scritto:
Is there a way to completely disable caching on dovecot?
Yes: mail_location = maildir:~/Maildir:INDEX=MEMORY
-- Alessio Cecchi http://www.linkedin.com/in/alessice
Alessio Cecchi skrev den 2015-06-01 15:29:
Il 20/05/2015 10:44, David Gessel ha scritto:
Is there a way to completely disable caching on dovecot?
Yes: mail_location = maildir:~/Maildir:INDEX=MEMORY
dont know if that really solve it, imho it just move the problem from disk cache to memory cache, it does not imho disable it
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Benny Pedersen me@junc.eu To: dovecot@dovecot.org Date: Mon Jun 01 2015 16:47:48 GMT+0300 (Arabic Standard Time)
Alessio Cecchi skrev den 2015-06-01 15:29:
Il 20/05/2015 10:44, David Gessel ha scritto:
Is there a way to completely disable caching on dovecot?
Yes: mail_location = maildir:~/Maildir:INDEX=MEMORY
dont know if that really solve it, imho it just move the problem from disk cache to memory cache, it does not imho disable it
It seemed to do the trick. Behavior finally seems normal. The best evidence: At 10:00:00-ish I made the change in the config file and at 10:02:29 I restarted the server.
It is now after 17:14 in Oakland and the logs are quiet.
09:00:06 host newsyslog[55292]: logfile turned over due to size>1000K 09:00:08 imap(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3558585, file=1434383291.M430136P55004.host,S=2380,W=2423:2,) 09:00:08 imap(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3558586, file=1434383253.M121801P54997.host,S=27419,W=28395:2,) 09:01:28 indexer-worker(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3558587, file=1434383997.M731644P55286.host,S=7334,W=7513:2,) 09:07:49 indexer-worker(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3561318, file=1434383997.M731644P55286.host,S=7334,W=7513:2,) 09:08:49 imap(user2): Warning: Maildir /mail/dom2/dmag/: Expunged message reappeared, giving a new UID (old uid=1846654, file=1434381278.M451318P54372.host,S=5013,W=5116:2,) 09:09:48 imap(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3561319, file=1405470941.M117568P19536.host.dom1.com,S=8266,W=8382:2,) 09:21:02 imap(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3564050, file=1434384469.M876726P55434.host,S=7297,W=7418:2,) 09:24:49 imap(user2): Warning: Maildir /mail/dom2/dmag/: Expunged message reappeared, giving a new UID (old uid=1847030, file=1434383414.M615990P55039.host,S=9890,W=10269:2,) 09:24:49 imap(user2): Warning: Maildir /mail/dom2/dmag/: Expunged message reappeared, giving a new UID (old uid=1847031, file=1434384445.M934994P55428.host,S=3405,W=3487:2,) 09:24:49 imap(user2): Warning: Maildir /mail/dom2/dmag/: Expunged message reappeared, giving a new UID (old uid=1847032, file=1434381278.M451318P54372.host,S=5013,W=5116:2,) 09:27:18 indexer-worker(user2): Warning: Maildir /mail/dom2/dmag/: Expunged message reappeared, giving a new UID (old uid=1847033, file=1434384562.M535709P55456.host,S=3403,W=3485:2,) 09:42:41 indexer-worker(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3565416, file=1434385257.M437928P55657.host,S=176241,W=178722:2,) 09:47:18 indexer-worker(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3568150, file=1434386561.M197796P56113.host,S=905854,W=917647:2,) 09:47:18 indexer-worker(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3568151, file=1434385257.M437928P55657.host,S=176241,W=178722:2,) 09:47:23 imap(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3568152, file=1434386561.M197796P56113.host,S=905854,W=917647:2,) 09:53:34 imap(user2): Warning: Maildir /mail/dom2/dmag/: Expunged message reappeared, giving a new UID (old uid=1847228, file=1434384562.M535709P55456.host,S=3403,W=3485:2,) 09:59:22 master: Warning: Killed with signal 15 (by pid=56486 uid=0 code=kill) 10:00:57 lda(user3): Warning: Maildir /mail/dom1.com/user3/: UIDVALIDITY changed (1404858902 -> 1433446125) 10:00:57 indexer-worker(user3): Warning: fts-lucene: Settings have changed, rebuilding index for mailbox 10:00:57 indexer-worker(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3569520, file=1434386838.M74634P56231.host,S=905827,W=917620:2,) 10:02:29 master: Warning: Killed with signal 15 (by pid=66696 uid=0 code=kill) 10:05:13 indexer-worker(user1): Warning: fts-lucene: Settings have changed, rebuilding index for mailbox 10:05:13 indexer-worker(user1): Error: stat(/mail/dom1.com/user1//.dovecot.sieve/tmp) failed: Not a directory 10:08:09 indexer-worker(user3): Warning: fts-lucene: Settings have changed, rebuilding index for mailbox 10:17:00 indexer-worker(user2): Warning: fts-lucene: Settings have changed, rebuilding index for mailbox 15:24:16 imap(user1): Error: stat(/mail/dom1.com/user1//.dovecot.sieve/tmp) failed: Not a directory
The last log file was turned over when it got greater than 1000K. It covered 1312 minutes and 3726 "expunged Message" warnings or one every 21 seconds. There hasn't been a single one in the 7+ hours since I moved the index to MEMORY.
Whatever is confusing the index state on disk, it is not happening in RAM.
On 16 Jun 2015, at 03:50, David Gessel gessel@blackrosetech.com wrote:
Alessio Cecchi skrev den 2015-06-01 15:29:
Il 20/05/2015 10:44, David Gessel ha scritto:
Is there a way to completely disable caching on dovecot?
Yes: mail_location = maildir:~/Maildir:INDEX=MEMORY
dont know if that really solve it, imho it just move the problem from disk cache to memory cache, it does not imho disable it
It seemed to do the trick. Behavior finally seems normal. The best evidence: At 10:00:00-ish I made the change in the config file and at 10:02:29 I restarted the server.
It is now after 17:14 in Oakland and the logs are quiet.
09:00:06 host newsyslog[55292]: logfile turned over due to size>1000K 09:00:08 imap(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3558585, file=1434383291.M430136P55004.host,S=2380,W=2423:2,) 09:00:08 imap(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3558586, file=1434383253.M121801P54997.host,S=27419,W=28395:2,)
..
The last log file was turned over when it got greater than 1000K. It covered 1312 minutes and 3726 "expunged Message" warnings or one every 21 seconds. There hasn't been a single one in the 7+ hours since I moved the index to MEMORY.
Whatever is confusing the index state on disk, it is not happening in RAM.
Well, it's also possible that the confusion is still happening, but Dovecot just doesn't notice it. If it is, IMAP clients may randomly not see all messages or may otherwise have strange behavior.
-------- Original Message -------- Subject: Re: Dovecot 2.2.16: disappearing messages, mismatched summaries, duplicated messages, excessive full re-downloads From: Timo Sirainen tss@iki.fi To: David Gessel gessel@blackrosetech.com Date: Wed Jun 17 2015 14:29:08 GMT+0300 (Arabic Standard Time)
On 16 Jun 2015, at 03:50, David Gessel gessel@blackrosetech.com wrote:
Alessio Cecchi skrev den 2015-06-01 15:29:
Il 20/05/2015 10:44, David Gessel ha scritto:
Is there a way to completely disable caching on dovecot?
Yes: mail_location = maildir:~/Maildir:INDEX=MEMORY
dont know if that really solve it, imho it just move the problem from disk cache to memory cache, it does not imho disable it
It seemed to do the trick. Behavior finally seems normal. The best evidence: At 10:00:00-ish I made the change in the config file and at 10:02:29 I restarted the server.
It is now after 17:14 in Oakland and the logs are quiet.
09:00:06 host newsyslog[55292]: logfile turned over due to size>1000K 09:00:08 imap(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3558585, file=1434383291.M430136P55004.host,S=2380,W=2423:2,) 09:00:08 imap(user1): Warning: Maildir /mail/dom1.com/user1/: Expunged message reappeared, giving a new UID (old uid=3558586, file=1434383253.M121801P54997.host,S=27419,W=28395:2,)
..
The last log file was turned over when it got greater than 1000K. It covered 1312 minutes and 3726 "expunged Message" warnings or one every 21 seconds. There hasn't been a single one in the 7+ hours since I moved the index to MEMORY.
Whatever is confusing the index state on disk, it is not happening in RAM.
Well, it's also possible that the confusion is still happening, but Dovecot just doesn't notice it. If it is, IMAP clients may randomly not see all messages or may otherwise have strange behavior.
As far as anyone has been able to determine, all artifacts are resolved. I believe it is fair to say "SOLVED." As I often start trying to solve problems by searching the list archives, I'll append my description of the artifacts as googlebait to the bottom of this message.
I am curious if setting INDEX=MEMORY "disables the index completely" as per http://wiki2.dovecot.org/MailLocation:
"If you really want to, you can also disable the index files completely by appending :INDEX=MEMORY."
Or if there are index files in memory as one might assume taking the directive literally, and if so, if these are functionally equivalent to, say, Courier IMAP's caching model.
Performance seems excellent, all features seem to work fine. A list of the artifacts that were observed before setting INDEX=MEMORY, all of which have been resolved by the directive change include:
*Client Artifacts*
Thunderbird 31.6 Win 7 Ultimate SP1:
- messages disappear and reappear with checks somewhat randomly.
- Sometimes full re-download of folders is triggered, also seems random
- Copies of messages appear, sometimes multiplying with each mail check up to about 5-8 or so of each message.
- The summary information in the list pane doesn't match the message headers in the preview pane
*All resolved with the fix*
Mulberry 4.08 Win 7 Ultimate SP1:
- messages disappear and reappear
- full re-scans of entire folders triggered occasionally when changing folders, but not always
- message list filled with semi-blank entries (message number, status flags, and dates are listed, but no sender, subject, or body is available). The time stamps do not appear to be correct "date received".
- message list fills with duplicates - the last of the set of duplicates, which are not necessarily sequentially numbered, has load-able body text and headers, but the others do not. There may be 3-5 copies, only one of which is the real message. The inbox is sequentially numbered by "message number" (the "natural order of the mailbox") and duplicates have unique numbers.
*All resolved with the fix*
Claws 3.10.1 Win 7 Ultimate SP1
- initial load is correct, but once claws tries to sync mail, it locks up and never releases (even after days). Claws is weird like that.
- Initial load is very fast
- Mostly works *
- claws still refuses to respond to the "exit" command and has to be force-quit. This is a widely reported claws issue.
- All mail tasks work fine, no artifacts other than refusing to quit.
Sylpheed 3.4.2 Win 7 Ultimate SP1
- mail list always looks fine, but sometimes clicking a message shows "can't display" in the preview pane
*Resolved with the fix*
Thunderbird 31.5 Linux Mint 17 Qaina 3.13.0-24-generic
- messages disappear and reappear with checks somewhat randomly.
- Sometimes full redownload of folders is triggered, also seems random
- Copies of messages appear, sometimes multiplying with each mail check
- The summary information in the list pane doesn't match the message headers in the preview pane
- wrong message total (every other client agrees on 2576 but TB-linux says 3242, perhaps counting dups)
*All resolved with the fix*
Claws 3.9.3 Linux Mint 17 Qaina 3.13.0-24-generic
- Occasionally shows "this message can't be displayed"
(haven't tested, but I'm guessing it is fixed)
K-9 5.004 Android 4.3
- messages appear and then disappear on the next check
- message body is occasionally blank (only subject and arrival time appear, no body preview line, clicking on the message shows "no text"
- K-9 reports an absurdly large number of messages to download
- K-9's notification message appears constantly with notifications of already downloaded messages
- Battery usage is excessive (K-9 sometimes uses more battery than the display)
- excessive bandwidth usage
*All resolved with the fix*
*Server artifacts:*
dovecot.log shows runs of this error: Apr 15 09:02:37 imap(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306286, file=1429102024.M826331P1156.host,S=1678,W=1724:2,S)
or this error: Apr 15 10:04:00 indexer-worker(user@domain.com): Warning: Maildir /mail/domain.com/user//.Sent: Expunged message reappeared, giving a new UID (old uid=306803, file=1428785463.M645546P27215.host,S=5389,W=5442:2,S)
# grep -c "Expunged message reappeared" dovecot.log.0 8981
On my server, "Expunged message reappeared" errors were being logged at a rate of about 3-5,000 per hour. After the fix, the error has not been logged at all.
# doveadm dump -t mailboxlog /mail/domain.com/user #0: rename 000000803de108b60f00000000000000 (1969-12-31 16:00:00) #24: 00000000000000000000000000000000 (1969-12-31 16:00:00) #48: 000000000000000000000000c8272100 (1969-12-31 16:01:04) #72: 00002e61726368697665732e32303031 (2031-02-20 10:50:40) Fatal: rec read() 10 != 24
After the fix:
# doveadm dump -t mailboxlog /mail/domain.com/user #0: rename 00000080fba020fd0600000000000000 (1969-12-31 16:00:00) #24: 00000000000000000000000000000000 (1969-12-31 16:00:00) #48: 000000000000000000000000e9a83900 (1969-12-31 16:02:08) #72: 0000646f7665636f742d75696476616c (2026-01-11 19:24:36) Fatal: rec read() 10 != 24
- OK, that's not fixed. :-(
doveadm dump -t fts-expunge-log /mail/domain.com/user
Fatal: Invalid record_size=2147483648 at offset 0
After the fix: # doveadm dump -t fts-expunge-log /mail/domain.com/user Fatal: Invalid record_size=2147483648 at offset 0
Perhaps there are still some corrupt messages? Any way to clean those up? This is either a different issue completely or it is a persistent artifact of the previous issue. I have done a
# find /mail/ -name "dovecot*" -type f -delete
since changing the directive followed by a jail reboot, are there any other files that should be deleted and allowed to recreate? doveadm_ files? lucene-indexes?
# doveadm dump -t log /mail/domain.com/user version = 0.0 hdr size = 0 index id = 0 file seq = 0 prev file = 0/0 create stamp = 0 initial modseq = 0 compat flags = 0 record: offset=0, type=unknown: 80000000, size=broken (3)
perhaps the size values should be recomputed with http://dovecot.org/tools/maildir-size-fix.pl ?
# doveadm dump -t thread /mail/domain.com/user Fatal: mmap() failed: Invalid argument
participants (7)
-
Alessio Cecchi
-
Benny Pedersen
-
Charles Marcus
-
David Gessel
-
Edgar Pettijohn III
-
Steffen Kaiser
-
Timo Sirainen