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-----