Hello folks, This morning I tried to open an old archive mail folder using Mutt. However, while fetching headers it aborted. Checking the dovecot log gave me this: @400000004fb21996267d37d4 imap(benv): Error: Cached message size smaller than expected (9115 < 9420) @400000004fb21996267e8bac imap(benv): Error: Maildir filename has wrong S value, renamed the file from /home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/cur/1260395566.28175.black,S=9115:2,S to /home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/cur/1260395566.28175.black,S=9420:2,S @400000004fb21996267e937c imap(benv): Error: Corrupted index cache file /home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/dovecot.index.cache: Broken physical size for mail UID 294 @400000004fb21996267eaaec imap(benv): Error: read(/home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/cur/1260395566.28175.black,S=9115:2,S) failed: Input/output error (uid=294) @400000004fb219962680683c imap(benv): Info: Disconnected: Internal error occurred. Refer to server log for more information. [2012-05-15 10:53:32] in=6503 out=192718 I've retried opening this folder several times, but each time Dovecot only fixes 1 file and then aborts. (the folder apparently has a lot more files with incorrect sizes). My question here is: Why does dovecot abort? Isn't the issue fixed after the rename? Also: The files are not corrupted or unreadable, reading them through the commandline works fine. I've looked through my backups and saw that at least half a year ago this mismatch in size was already present. I've been running dovecot for quite a while, so the cause of this size mismatch might very well be a issue in an older version of dovecot / my configuration. Right now I'm running dovecot 2.1.6, but I've been running the v1.2 version for quite a while before that. Is this something that can be improved in dovecot so it doesn't abort after 1 rename? (of course I could script a rename operation, but that seems like a workaround to me) Thanks for reading. Wouter. My current configuration: ========================# 2.1.6: /etc/dovecot/dovecot.conf # OS: Linux 2.6.32.32-g3d14ce7 x86_64 Slackware 11.0.0 base_dir = /var/run/dovecot2/ disable_plaintext_auth = no first_valid_uid = 89 info_log_path = /dev/stderr last_valid_uid = 89 log_path = /dev/stderr log_timestamp mail_debug = yes mail_location = maildir:~/Maildir mail_max_userip_connections = 50 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 e nvironment mailbox date namespace { inbox = yes location prefix = INBOX. separator = . type = private } passdb { driver = vpopmail } plugin { autocreate = INBOX.Spam quota = maildir sieve = ~/.sieve/dovecot.sieve sieve_dir = ~/.sieve sieve_global_dir = /etc/dovecot/sieve/ sieve_subaddress_sep = -+ } protocols = imap pop3 sieve service auth { unix_listener auth-master { group = vchkpw mode = 0660 } unix_listener auth-userdb { group = vchkpw mode = 0660 } } service imap-login { inet_listener imap { address = [::] * port = 143 } inet_listener imaps { address = [::] * port = 993 } process_limit = 256 process_min_avail = 3 service_count = 1 user = dovecot } service managesieve-login { process_limit = 256 process_min_avail = 3 service_count = 1 user = dovecot } service pop3-login { inet_listener pop3 { address = [::] * port = 110 } inet_listener pop3s { address = [::] * port = 995 } process_limit = 256 process_min_avail = 3 service_count = 1 user = dovecot } ssl_cert = </var/qmail/control/servercert.pem ssl_cipher_list = ALL:!LOW ssl_key = </var/qmail/control/servercert.pem userdb { driver = vpopmail } verbose_proctitle = yes protocol lda { hostname = mail.benv.junerules.com info_log_path = /var/log/dovecot/dovecot2-deliver.log log_path = /var/log/dovecot/dovecot2-deliver-errors.log mail_plugins = sieve postmaster_address = postmaster at benv.junerules.com sendmail_path = /var/qmail/bin/sendmail } protocol imap { imap_max_line_length = 64 k mail_plugins = quota imap_quota autocreate } protocol pop3 { mail_plugins = quota autocreate pop3_no_flag_updates = no pop3_uidl_format = %v-%u } =================================
On Tue, 2012-05-15 at 12:23 +0200, Wouter de Geus wrote:> Hello folks, > > This morning I tried to open an old archive mail folder using Mutt. > However, while fetching headers it aborted. > Checking the dovecot log gave me this: > > @400000004fb21996267d37d4 imap(benv): Error: Cached message size smaller than expected (9115 < 9420) > @400000004fb21996267e8bac imap(benv): Error: Maildir filename has wrong S value, renamed the file from /home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/cur/1260395566.28175.black,S=9115:2,S to /home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/cur/1260395566.28175.black,S=9420:2,S > @400000004fb21996267e937c imap(benv): Error: Corrupted index cache file /home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/dovecot.index.cache: Broken physical size for mail UID 294 > @400000004fb21996267eaaec imap(benv): Error: read(/home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/cur/1260395566.28175.black,S=9115:2,S) failed: Input/output error (uid=294) > @400000004fb219962680683c imap(benv): Info: Disconnected: Internal error occurred. Refer to server log for more information. [2012-05-15 10:53:32] in=6503 out=192718 > > I've retried opening this folder several times, but each time Dovecot only fixes 1 file and then aborts. > (the folder apparently has a lot more files with incorrect sizes). > My question here is: Why does dovecot abort? Isn't the issue fixed after the rename?That file was fixed, but you probably have tons of them and it aborts after each one. With IMAP protocol there's really no other good way to do this. I guess if it notices one file being wrong it could just decide to go into error recovery check and read through all of the maildir files, but that's annoying extra piece of code for something that shouldn't happen anyway.. You should be able to manually fix them by reading them via doveadm, something like: doveadm fetch -u benv text all > /dev/null> Also: The files are not corrupted or unreadable, reading them through the commandline works fine. > I've looked through my backups and saw that at least half a year ago this mismatch in size was already present. > > I've been running dovecot for quite a while, so the cause of this size mismatch might very well be a issue in an older version of dovecot / my configuration. > Right now I'm running dovecot 2.1.6, but I've been running the v1.2 version for quite a while before that.Old Dovecot versions didn't notice the problem. You can make v2.1 also just ignore the wrong sizes with maildir_broken_filename_sizes=yes.
On 15.5.12 12:23, Wouter de Geus wrote:> Hello folks, > > This morning I tried to open an old archive mail folder using Mutt. > However, while fetching headers it aborted. > Checking the dovecot log gave me this: > > @400000004fb21996267d37d4 imap(benv): Error: Cached message size smaller than expected (9115 < 9420) > @400000004fb21996267e8bac imap(benv): Error: Maildir filename has wrong S value, renamed the file from /home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/cur/1260395566.28175.black,S=9115:2,S to /home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/cur/1260395566.28175.black,S=9420:2,S > @400000004fb21996267e937c imap(benv): Error: Corrupted index cache file /home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/dovecot.index.cache: Broken physical size for mail UID 294 > @400000004fb21996267eaaec imap(benv): Error: read(/home/vpopmail/domains/benv.junerules.com/benv/Maildir/.Old.2009/cur/1260395566.28175.black,S=9115:2,S) failed: Input/output error (uid=294) > @400000004fb219962680683c imap(benv): Info: Disconnected: Internal error occurred. Refer to server log for more information. [2012-05-15 10:53:32] in=6503 out=192718 > > I've retried opening this folder several times, but each time Dovecot only fixes 1 file and then aborts. > (the folder apparently has a lot more files with incorrect sizes). > My question here is: Why does dovecot abort? Isn't the issue fixed after the rename? > > Also: The files are not corrupted or unreadable, reading them through the commandline works fine. > I've looked through my backups and saw that at least half a year ago this mismatch in size was already present. > > I've been running dovecot for quite a while, so the cause of this size mismatch might very well be a issue in an older version of dovecot / my configuration. > Right now I'm running dovecot 2.1.6, but I've been running the v1.2 version for quite a while before that. > > Is this something that can be improved in dovecot so it doesn't abort after 1 rename? > (of course I could script a rename operation, but that seems like a workaround to me) > > Thanks for reading. > > Wouter. > > > > > My current configuration: > ========================> # 2.1.6: /etc/dovecot/dovecot.conf > # OS: Linux 2.6.32.32-g3d14ce7 x86_64 Slackware 11.0.0 > base_dir = /var/run/dovecot2/ > disable_plaintext_auth = no > first_valid_uid = 89 > info_log_path = /dev/stderr > last_valid_uid = 89 > log_path = /dev/stderr > log_timestamp > mail_debug = yes > mail_location = maildir:~/Maildir > mail_max_userip_connections = 50 > 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 e > nvironment mailbox date > namespace { > inbox = yes > location > prefix = INBOX. > separator = . > type = private > } > passdb { > driver = vpopmail > } > plugin { > autocreate = INBOX.Spam > quota = maildir > sieve = ~/.sieve/dovecot.sieve > sieve_dir = ~/.sieve > sieve_global_dir = /etc/dovecot/sieve/ > sieve_subaddress_sep = -+ > } > protocols = imap pop3 sieve > service auth { > unix_listener auth-master { > group = vchkpw > mode = 0660 > } > unix_listener auth-userdb { > group = vchkpw > mode = 0660 > } > } > service imap-login { > inet_listener imap { > address = [::] * > port = 143 > } > inet_listener imaps { > address = [::] * > port = 993 > } > process_limit = 256 > process_min_avail = 3 > service_count = 1 > user = dovecot > } > service managesieve-login { > process_limit = 256 > process_min_avail = 3 > service_count = 1 > user = dovecot > } > service pop3-login { > inet_listener pop3 { > address = [::] * > port = 110 > } > inet_listener pop3s { > address = [::] * > port = 995 > } > process_limit = 256 > process_min_avail = 3 > service_count = 1 > user = dovecot > } > ssl_cert = </var/qmail/control/servercert.pem > ssl_cipher_list = ALL:!LOW > ssl_key = </var/qmail/control/servercert.pem > userdb { > driver = vpopmail > } > verbose_proctitle = yes > protocol lda { > hostname = mail.benv.junerules.com > info_log_path = /var/log/dovecot/dovecot2-deliver.log > log_path = /var/log/dovecot/dovecot2-deliver-errors.log > mail_plugins = sieve > postmaster_address = postmaster at benv.junerules.com > sendmail_path = /var/qmail/bin/sendmail > } > protocol imap { > imap_max_line_length = 64 k > mail_plugins = quota imap_quota autocreate > } > protocol pop3 { > mail_plugins = quota autocreate > pop3_no_flag_updates = no > pop3_uidl_format = %v-%u > } > ================================>I've been facing the same issue today in a similar setup (qmail + vpopmail + dovecot) and figured, that the qmail maildir++ patch I'm using miscalculates the size of mail, since it ignores Delivered-To and Return-Path in the size calculation. Fixing this and reinstalling qmail-local ( plus fixing existing mail using doveadm fetch -u username text all > /dev/null ) solved the problem for me. The problematic line in qmail-local.c is: s += fmt_ulong(s,st.st_size); *s++ = 0; which should be: s += fmt_ulong(s,st.st_size+rpline.len+dtline.len); *s++ = 0; (for FreeBSD users: I submitted a patch to the qmail port, fixing this) http://www.freebsd.org/cgi/query-pr.cgi?pr=ports/168870 Fixing this also fixed fts_squat for me (dovecot 2.1.7) -- Michael