[Dovecot] Various uidlist and index errors with 1.1 on NFS
Two nights ago I took a leap and extended my testing of dovecot 1.1 by replacing 1.0 for the approx 15 users I had on 1.0. At that time I also for the first time tried dovecot 1.1 in a load balanced 2 server configuration with indexes on NFS. I was hoping I did this right, using the mail_nfs params and 1.1 so fchown etc would flush the access cache, but I am getting a number of messages and errors that indicate things aren't happy. Attaching error logs. Some of the errors were caused by me running multiple mail clients including mutt, Thunderbird, Outlook Express, other users may be using one or more copies of thunderbird, or possibly other clients. Most commonly thunderbird. Any help or advice would be appreciated. My goal is to have shared indexes between servers since I will eventually have 4. I'd prefer to avoid maintaining some kind of user->server preference mapping in a proxy (haven't looked into it yet). Thanks.
# 1.1.beta6: /usr/local/etc/dovecot.conf ssl_cert_file: /usr/local/etc/apache2/ssl/mail.pem ssl_key_file: /usr/local/etc/apache2/ssl/mail.pem login_dir: /var/run/dovecot/login login_executable: /usr/local/libexec/dovecot/imap-login verbose_proctitle: yes first_valid_uid: 1000 first_valid_gid: 1000 mail_extra_groups: postlocal mail_location: maildir:%h/Maildir:CONTROL=%h/Maildir/dovecot/private/control:INDEX=%h/Maildir/dovecot/private/indexes mmap_disable: yes mail_nfs_storage: yes mail_nfs_index: yes mail_plugins: acl mail_log_max_lines_per_sec: 0 imap_client_workarounds: delay-newmail netscape-eoh tb-extra-mailbox-sep namespace: type: private separator: / inbox: yes list: yes subscriptions: yes namespace: type: private separator: / prefix: mail/ hidden: yes subscriptions: yes namespace: type: private separator: / prefix: Mail/ hidden: yes subscriptions: yes namespace: type: public separator: / prefix: #shared/decs/ location: maildir:/egr/mail/shared/decs:CONTROL=%h/Maildir/dovecot/public/control/decs:INDEX=%h/Maildir/dovecot/public/indexes/decs list: yes subscriptions: yes auth default: passdb: driver: pam userdb: driver: passwd args: system_user= socket: type: listen client: path: /var/spool/postfix/private/auth mode: 384 user: postfix group: postfix plugin: acl: vfile:/usr/local/etc/dovecot-acls:cache_secs=10
On Tue, 2007-11-06 at 15:57 -0500, Adam McDougall wrote:
Two nights ago I took a leap and extended my testing of dovecot 1.1 by replacing 1.0 for the approx 15 users I had on 1.0. At that time I also for the first time tried dovecot 1.1 in a load balanced 2 server configuration with indexes on NFS.
I hadn't actually tested this myself. Would be nice if someone gave me access to a NFS test system, would be much easier to test and fix these problems. :)
What OS are you using on NFS clients?
Nov 4 23:32:23 boomhauer dovecot: IMAP(mcdouga9): Trying to close mailbox support.2005.01-Jan with open transactions
Probably some error handling path forgot to free the transaction. Would be nice to know how to reproduce it.
Nov 5 01:11:43 boomhauer dovecot: IMAP(mcdouga9): Corrupted transaction log file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log: Unexpected garbage at EOF
Either writing really left some partially written data there, or attribute cache flushing doesn't work.
Nov 6 09:12:26 boomhauer dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/control/decs/.support/dovecot-uidlist: Duplicate file entry: 1189447198.M910150P10430.hill:2,RS
Sources explain this as:
/* This can happen if expunged file is moved back and the file
was appended to uidlist. */So that would mean that readdir() skipped some files and later found them again. But this shouldn't happen as long as Dovecot is the only one accessing the maildir, because it locks its syncs..
Nov 5 15:26:53 hill dovecot: IMAP(mcdouga9): file mail-index-sync-update.c: line 599: unreached
I replaced this crash with a nice error message. :)
On Sat, Nov 10, 2007 at 07:54:15PM +0200, Timo Sirainen wrote:
On Tue, 2007-11-06 at 15:57 -0500, Adam McDougall wrote:
Two nights ago I took a leap and extended my testing of dovecot 1.1 by replacing 1.0 for the approx 15 users I had on 1.0. At that time I also for the first time tried dovecot 1.1 in a load balanced 2 server configuration with indexes on NFS.
I hadn't actually tested this myself. Would be nice if someone gave me access to a NFS test system, would be much easier to test and fix these problems. :)
I'd be more than happy to give you access to some of my servers.
I'll email you privately about that. If you think the corruption
is resolvable, I'd be happy if it could be worked out to provide
a better service to my users.
What OS are you using on NFS clients?
FreeBSD 6.2
Nov 4 23:32:23 boomhauer dovecot: IMAP(mcdouga9): Trying to close mailbox support.2005.01-Jan with open transactions
Probably some error handling path forgot to free the transaction. Would be nice to know how to reproduce it.
I agree it would be nice. If I see it again and find a way to isolate it, I will. Perhaps it is caused when a client gets disconnected for some reason. Could just be a symptom of index problems that could get resolved some other way.
Nov 5 01:11:43 boomhauer dovecot: IMAP(mcdouga9): Corrupted transaction log file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log: Unexpected garbage at EOF
Either writing really left some partially written data there, or attribute cache flushing doesn't work.
Nov 6 09:12:26 boomhauer dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/control/decs/.support/dovecot-uidlist: Duplicate file entry: 1189447198.M910150P10430.hill:2,RS
Sources explain this as:
/* This can happen if expunged file is moved back and the file
was appended to uidlist. */So that would mean that readdir() skipped some files and later found them again. But this shouldn't happen as long as Dovecot is the only one accessing the maildir, because it locks its syncs..
Nov 5 15:26:53 hill dovecot: IMAP(mcdouga9): file mail-index-sync-update.c: line 599: unreached
I replaced this crash with a nice error message. :)
I'm beginning to understand the problem. Or at least one of them. :)
Dovecot is currently flushing attribute cache for files it wants to stat/open. But that's not enough. It also has to flush attribute cache for the directory, or it might stat/open a file that has already been unlinked (but which still has links somewhere in the filesystem so that it doesn't fail with ESTALE).
dotlock_use_excl=yes seems to help somewhat with this problem for now. It also gives better performance.
On Sun, Nov 11, 2007 at 02:34:33AM +0200, Timo Sirainen wrote:
I'm beginning to understand the problem. Or at least one of them. :)
Dovecot is currently flushing attribute cache for files it wants to stat/open. But that's not enough. It also has to flush attribute cache for the directory, or it might stat/open a file that has already been unlinked (but which still has links somewhere in the filesystem so that it doesn't fail with ESTALE).
dotlock_use_excl=yes seems to help somewhat with this problem for now. It also gives better performance.
I'm assuming that only helps if I use dotlock locking, right? I've left it at the default locking method so far except for a brief period a few nights ago, when I tried dotlock but it seemed no better (although I neglected to try dotlock_use_excl).
On Sat, 2007-11-10 at 19:51 -0500, Adam McDougall wrote:
On Sun, Nov 11, 2007 at 02:34:33AM +0200, Timo Sirainen wrote:
I'm beginning to understand the problem. Or at least one of them. :)
Dovecot is currently flushing attribute cache for files it wants to stat/open. But that's not enough. It also has to flush attribute cache for the directory, or it might stat/open a file that has already been unlinked (but which still has links somewhere in the filesystem so that it doesn't fail with ESTALE).
dotlock_use_excl=yes seems to help somewhat with this problem for now. It also gives better performance.
I'm assuming that only helps if I use dotlock locking, right?
No, maildir always uses dotlocks.
This is getting difficult though. After many hours I've finally gotten it to work properly without indexes. But even that required a pretty evil hack. It looks like the only way I can get FreeBSD to flush its filename cache (or whatever it's called that maps filenames to inodes) is to call rmdir() to the directory and hope that it fails with ENOTEMPTY. So this can't be safely done if the directory may be empty, as is easily possible with Maildir/cur and Maildir/new directories..
With indexes enabled it then starts giving errors immediately about transaction logs. I think I'll leave figuring that out for later. I'm guessing the read cache flushing code doesn't work properly either.
I hope Linux supports cache flushes better..
On Sun, Nov 11, 2007 at 06:19:21AM +0200, Timo Sirainen wrote:
On Sat, 2007-11-10 at 19:51 -0500, Adam McDougall wrote:
On Sun, Nov 11, 2007 at 02:34:33AM +0200, Timo Sirainen wrote:
I'm beginning to understand the problem. Or at least one of them. :)
Dovecot is currently flushing attribute cache for files it wants to stat/open. But that's not enough. It also has to flush attribute cache for the directory, or it might stat/open a file that has already been unlinked (but which still has links somewhere in the filesystem so that it doesn't fail with ESTALE).
dotlock_use_excl=yes seems to help somewhat with this problem for now. It also gives better performance.
I'm assuming that only helps if I use dotlock locking, right?
No, maildir always uses dotlocks.
This is getting difficult though. After many hours I've finally gotten it to work properly without indexes. But even that required a pretty evil hack. It looks like the only way I can get FreeBSD to flush its filename cache (or whatever it's called that maps filenames to inodes) is to call rmdir() to the directory and hope that it fails with ENOTEMPTY. So this can't be safely done if the directory may be empty, as is easily possible with Maildir/cur and Maildir/new directories..
Wow, scary, but at least finding one awful way to make it work is starting on the road to finding a less awful way :) If I had more time, I'd start looking around the kernel source myself, but I have to get the rest of this project off the ground.
With indexes enabled it then starts giving errors immediately about transaction logs. I think I'll leave figuring that out for later. I'm guessing the read cache flushing code doesn't work properly either.
No problem, thanks for looking into it. I think I will be satisfied for now with per-server index directories. Do you think it should be safe to have them on NFS as long as only one host accesses that index directory? (with possible, and likely multiple dovecot processes for one user on that host) Also, should I start using dotlock_use_excl anyway as long as it appears to work?
I hope Linux supports cache flushes better..
On Sat, 2007-11-10 at 23:32 -0500, Adam McDougall wrote:
No, maildir always uses dotlocks.
This is getting difficult though. After many hours I've finally gotten it to work properly without indexes. But even that required a pretty evil hack. It looks like the only way I can get FreeBSD to flush its filename cache (or whatever it's called that maps filenames to inodes) is to call rmdir() to the directory and hope that it fails with ENOTEMPTY. So this can't be safely done if the directory may be empty, as is easily possible with Maildir/cur and Maildir/new directories..
Wow, scary, but at least finding one awful way to make it work is starting on the road to finding a less awful way :) If I had more time, I'd start looking around the kernel source myself, but I have to get the rest of this project off the ground.
I figured out that rmdir() flushing by looking at FreeBSD sources. :) I also tried a few other ways that looked promising, but nothing else seemed to work.
With indexes enabled it then starts giving errors immediately about transaction logs. I think I'll leave figuring that out for later. I'm guessing the read cache flushing code doesn't work properly either.
No problem, thanks for looking into it. I think I will be satisfied for now with per-server index directories. Do you think it should be safe to have them on NFS as long as only one host accesses that index directory?
Yes.
Also, should I start using dotlock_use_excl anyway as long as it appears to work?
Yes. I might even make it the default, since it's broken only with some really old NFS setups.
Thanks so much Timo, all of the errors below seem when using 1.1beta9 and a shared index on NFS. Great!
On Tue, Nov 06, 2007 at 03:57:24PM -0500, Adam McDougall wrote:
Two nights ago I took a leap and extended my testing of dovecot 1.1 by replacing 1.0 for the approx 15 users I had on 1.0. At that time I also for the first time tried dovecot 1.1 in a load balanced 2 server configuration with indexes on NFS. I was hoping I did this right, using the mail_nfs params and 1.1 so fchown etc would flush the access cache, but I am getting a number of messages and errors that indicate things aren't happy. Attaching error logs. Some of the errors were caused by me running multiple mail clients including mutt, Thunderbird, Outlook Express, other users may be using one or more copies of thunderbird, or possibly other clients. Most commonly thunderbird. Any help or advice would be appreciated. My goal is to have shared indexes between servers since I will eventually have 4. I'd prefer to avoid maintaining some kind of user->server preference mapping in a proxy (haven't looked into it yet). Thanks.
# 1.1.beta6: /usr/local/etc/dovecot.conf ssl_cert_file: /usr/local/etc/apache2/ssl/mail.pem ssl_key_file: /usr/local/etc/apache2/ssl/mail.pem login_dir: /var/run/dovecot/login login_executable: /usr/local/libexec/dovecot/imap-login verbose_proctitle: yes first_valid_uid: 1000 first_valid_gid: 1000 mail_extra_groups: postlocal mail_location: maildir:%h/Maildir:CONTROL=%h/Maildir/dovecot/private/control:INDEX=%h/Maildir/dovecot/private/indexes mmap_disable: yes mail_nfs_storage: yes mail_nfs_index: yes mail_plugins: acl mail_log_max_lines_per_sec: 0 imap_client_workarounds: delay-newmail netscape-eoh tb-extra-mailbox-sep namespace: type: private separator: / inbox: yes list: yes subscriptions: yes namespace: type: private separator: / prefix: mail/ hidden: yes subscriptions: yes namespace: type: private separator: / prefix: Mail/ hidden: yes subscriptions: yes namespace: type: public separator: / prefix: #shared/decs/ location: maildir:/egr/mail/shared/decs:CONTROL=%h/Maildir/dovecot/public/control/decs:INDEX=%h/Maildir/dovecot/public/indexes/decs list: yes subscriptions: yes auth default: passdb: driver: pam userdb: driver: passwd args: system_user= socket: type: listen client: path: /var/spool/postfix/private/auth mode: 384 user: postfix group: postfix plugin: acl: vfile:/usr/local/etc/dovecot-acls:cache_secs=10
List of errors: "Trying to close mailbox with open transactions" "Corrupted transaction log file Unexpected garbage at EOF" "fscking index file" "Transaction log got desynced for index" "start_offset (3872) > current sync_offset" "Fixed index file" "log_file_head_offset 3872 -> 3680" "Corrupted transaction log file record size too small" "Transaction log file marked corrupted" "file mail-index-sync-update.c: line 599: unreached" "Duplicate file entry:" "Corrupted transaction log file header update extends beyond record size"
Nov 4 22:17:03 boomhauer dovecot: Dovecot v1.1.beta6 starting up Nov 4 23:32:23 boomhauer dovecot: IMAP(mcdouga9): Trying to close mailbox support.2005.01-Jan with open transactions Nov 4 23:32:23 boomhauer dovecot: child 46161 (imap) killed with signal 6 Nov 5 01:11:43 boomhauer dovecot: IMAP(mcdouga9): Corrupted transaction log file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log: Unexpected garbage at EOF Nov 5 01:13:59 boomhauer dovecot: IMAP(mcdouga9): Corrupted transaction log file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log: Unexpected garbage at EOF Nov 5 01:13:59 boomhauer dovecot: IMAP(mcdouga9): Disconnected: Internal error occurred. Refer to server log for more information. [2007-11-05 01:13:59] bytes=4127/4532482 Nov 5 01:15:43 boomhauer dovecot: IMAP(mcdouga9): fscking index file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index Nov 5 01:16:43 boomhauer dovecot: IMAP(mcdouga9): fscking index file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index Nov 5 01:17:43 boomhauer dovecot: IMAP(mcdouga9): Transaction log got desynced for index /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index Nov 5 01:17:43 boomhauer dovecot: IMAP(mcdouga9): Disconnected: Mailbox is in inconsistent state, please relogin. bytes=4299/5007523 Nov 5 02:06:38 boomhauer dovecot: IMAP(mcdouga9): /home/mcdouga9/Maildir/dovecot/public/indexes/decs/.network/dovecot.index.log: start_offset (3872) > current sync_offset (3680) Nov 5 02:06:38 boomhauer dovecot: IMAP(mcdouga9): fscking index file /home/mcdouga9/Maildir/dovecot/public/indexes/decs/.network/dovecot.index Nov 5 02:06:38 boomhauer dovecot: IMAP(mcdouga9): Fixed index file /home/mcdouga9/Maildir/dovecot/public/indexes/decs/.network/dovecot.index: log_file_head_offset 3872 -> 3680 Nov 5 02:06:38 boomhauer dovecot: IMAP(mcdouga9): Fixed index file /home/mcdouga9/Maildir/dovecot/public/indexes/decs/.network/dovecot.index: log_file_tail_offset 3872 -> 3680 Nov 5 02:06:38 boomhauer dovecot: IMAP(mcdouga9): Disconnected: Logged out bytes=1133/5754 Nov 5 10:06:50 boomhauer dovecot: IMAP(mcdouga9): Corrupted transaction log file /home/mcdouga9/Maildir/dovecot/public/indexes/decs/.network/dovecot.index.log: record size too small (type=0x0, offset=3928, size=0) Nov 5 10:07:46 boomhauer dovecot: IMAP(mcdouga9): Transaction log file /home/mcdouga9/Maildir/dovecot/public/indexes/decs/.network/dovecot.index.log: marked corrupted Nov 5 13:43:30 boomhauer dovecot: IMAP(nguye140): /home/nguye140/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: start_offset (5572) > current sync_offset (5284) Nov 5 13:43:30 boomhauer dovecot: IMAP(nguye140): fscking index file /home/nguye140/Maildir/dovecot/public/indexes/decs/.support/dovecot.index Nov 5 13:43:30 boomhauer dovecot: IMAP(nguye140): Fixed index file /home/nguye140/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_head_offset 5572 -> 5284 Nov 5 13:43:30 boomhauer dovecot: IMAP(nguye140): Fixed index file /home/nguye140/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_tail_offset 5572 -> 5284 Nov 5 15:03:00 boomhauer dovecot: IMAP(mcdouga9): file mail-index-sync-update.c: line 599: unreached Nov 5 15:03:00 boomhauer dovecot: child 78214 (imap) killed with signal 6 Nov 5 16:03:56 boomhauer dovecot: IMAP(mcdouga9): Transaction log file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log: marked corrupted Nov 6 09:12:26 boomhauer dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/control/decs/.support/dovecot-uidlist: Duplicate file entry: 1189447198.M910150P10430.hill:2,RS Nov 6 09:12:26 boomhauer dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/control/decs/.support/dovecot-uidlist: Duplicate file entry: 1193427305.M277014P88682.boomhauer:2,S Nov 6 09:12:26 boomhauer dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/control/decs/.support/dovecot-uidlist: Duplicate file entry: 1194025661.M154932P28762.boomhauer:2,S Nov 6 09:12:26 boomhauer dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/control/decs/.support/dovecot-uidlist: Duplicate file entry: 1194025665.M107072P28771.boomhauer:2,S Nov 6 09:12:26 boomhauer dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/control/decs/.support/dovecot-uidlist: Duplicate file entry: 1194027883.M070903P52370.hill:2,S Nov 6 09:12:26 boomhauer dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/control/decs/.support/dovecot-uidlist: Duplicate file entry: 1194267366.M742511P64048.boomhauer:2,S Nov 6 09:12:26 boomhauer dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/control/decs/.support/dovecot-uidlist: Duplicate file entry: 1194278384.M003974P96264.hill:2,S Nov 6 09:12:26 boomhauer dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/control/decs/.support/dovecot-uidlist: Duplicate file entry: 1194279851.M701280P97579.hill:2,S (a number of them, about 50? seems like the same 50 messages complained about like this, at 9:12:26, 9:14:04, 09:14:46, 09:18:51, 14:42:49.
Nov 6 14:43:25 boomhauer dovecot: IMAP(jelneckt): Corrupted transaction log file /home/jelneckt/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: record size too small (type=0x0, offset=26984, size=0) Nov 6 14:47:26 boomhauer dovecot: IMAP(jelneckt): Transaction log file /home/jelneckt/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: marked corrupted Nov 6 15:16:35 boomhauer dovecot: IMAP(jelneckt): Disconnected for inactivity bytes=825/850
Nov 5 01:16:53 hill dovecot: IMAP(mcdouga9): Transaction log file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log: marked corrupted Nov 5 01:21:51 hill dovecot: IMAP(mcdouga9): Trying to close mailbox freebsd-cvs with open transactions Nov 5 01:21:51 hill dovecot: child 75087 (imap) killed with signal 6 Nov 5 02:06:49 hill dovecot: IMAP(mcdouga9): /home/mcdouga9/Maildir/dovecot/public/control/decs/.network/dovecot-uidlist: Duplicate file entry: 1194235915.M316064P47248.boomhauer:2,ST Nov 5 02:06:49 hill dovecot: IMAP(mcdouga9): /home/mcdouga9/Maildir/dovecot/public/control/decs/.network/dovecot-uidlist: Duplicate file entry: 1194240041.M550300P72969.hill:2,ST Nov 5 02:06:49 hill dovecot: IMAP(mcdouga9): /home/mcdouga9/Maildir/dovecot/public/control/decs/.network/dovecot-uidlist: Duplicate file entry: 1194240355.M754858P73301.hill:2,ST Nov 5 02:06:49 hill dovecot: IMAP(mcdouga9): /home/mcdouga9/Maildir/dovecot/public/control/decs/.network/dovecot-uidlist: Duplicate file entry: 1194243924.M066185P51525.boomhauer:2,ST Nov 5 02:06:49 hill dovecot: IMAP(mcdouga9): /home/mcdouga9/Maildir/dovecot/public/control/decs/.network/dovecot-uidlist: Duplicate file entry: 1194244965.M990468P52239.boomhauer:2,ST Nov 5 02:06:49 hill dovecot: IMAP(mcdouga9): /home/mcdouga9/Maildir/dovecot/public/control/decs/.network/dovecot-uidlist: Duplicate file entry: 1194246389.M336415P76883.hill:2, Nov 5 10:08:38 hill dovecot: IMAP(mcdouga9): Transaction log got desynced for index /home/mcdouga9/Maildir/dovecot/public/indexes/decs/.network/dovecot.index Nov 5 10:08:38 hill dovecot: IMAP(mcdouga9): Disconnected: Mailbox is in inconsistent state, please relogin. bytes=19157/57504 Nov 5 14:50:57 hill dovecot: IMAP(mcdouga9): Corrupted transaction log file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log: header update extends beyond record size Nov 5 14:50:57 hill dovecot: IMAP(mcdouga9): fscking index file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index Nov 5 15:05:57 hill dovecot: IMAP(mcdouga9): fscking index file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index Nov 5 15:20:57 hill dovecot: IMAP(mcdouga9): fscking index file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index Nov 5 15:26:53 hill dovecot: IMAP(mcdouga9): file mail-index-sync-update.c: line 599: unreached Nov 5 15:26:53 hill dovecot: child 72615 (imap) killed with signal 6 Nov 5 15:35:57 hill dovecot: IMAP(mcdouga9): fscking index file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index Nov 5 15:50:57 hill dovecot: IMAP(mcdouga9): fscking index file /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index Nov 5 16:03:59 hill dovecot: IMAP(mcdouga9): Invalid transaction log size (28600 vs 27840): /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log Nov 5 16:03:59 hill dovecot: IMAP(mcdouga9): Invalid transaction log size (28600 vs 27840): /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log Nov 5 16:03:59 hill dovecot: IMAP(mcdouga9): Invalid transaction log size (28600 vs 27840): /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log Nov 5 16:05:57 hill dovecot: IMAP(mcdouga9): Transaction log got desynced for index /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index Nov 5 16:05:57 hill dovecot: IMAP(mcdouga9): Disconnected: Mailbox is in inconsistent state, please relogin. bytes=23965/37200957 Nov 5 16:05:59 hill dovecot: IMAP(mcdouga9): Invalid transaction log size (28600 vs 27840): /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log Nov 5 16:05:59 hill dovecot: IMAP(mcdouga9): Invalid transaction log size (28600 vs 27840): /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log Nov 5 16:05:59 hill dovecot: IMAP(mcdouga9): Invalid transaction log size (28600 vs 27840): /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log Nov 5 16:07:59 hill dovecot: IMAP(mcdouga9): Invalid transaction log size (28600 vs 27840): /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log Nov 5 16:07:59 hill dovecot: IMAP(mcdouga9): Invalid transaction log size (28600 vs 27840): /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log Nov 5 16:08:00 hill dovecot: IMAP(mcdouga9): Invalid transaction log size (28600 vs 27840): /home/mcdouga9/Maildir/dovecot/private/indexes/.INBOX/dovecot.index.log (many of these repeating (28600 vs 27840), pattern seemed to be 3 at once, every 2 minutes, continuing up to the present time Nov 6 14:49) Nov 6 09:12:11 hill dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: start_offset (13044) > current sync_offset (12384) Nov 6 09:12:11 hill dovecot: IMAP(walbyjon): fscking index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index Nov 6 09:12:11 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_head_offset 13044 -> 12384 Nov 6 09:12:11 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_tail_offset 13044 -> 12384 Nov 6 09:13:12 hill dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: start_offset (15552) > current sync_offset (13456) Nov 6 09:13:12 hill dovecot: IMAP(walbyjon): fscking index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index Nov 6 09:13:12 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_head_offset 15552 -> 13456 Nov 6 09:13:12 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_tail_offset 15552 -> 13456 Nov 6 09:14:43 hill dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: start_offset (16648) > current sync_offset (14424) Nov 6 09:14:43 hill dovecot: IMAP(walbyjon): fscking index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index Nov 6 09:14:43 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_head_offset 16648 -> 14424 Nov 6 09:14:43 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_tail_offset 16648 -> 14424 Nov 6 09:16:44 hill dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: start_offset (17700) > current sync_offset (15328) Nov 6 09:16:44 hill dovecot: IMAP(walbyjon): fscking index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index Nov 6 09:16:44 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_head_offset 17700 -> 15328 Nov 6 09:16:44 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_tail_offset 17700 -> 15328 Nov 6 09:19:12 hill dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: start_offset (19048) > current sync_offset (16216) Nov 6 09:19:12 hill dovecot: IMAP(walbyjon): fscking index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index Nov 6 09:19:12 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_head_offset 19048 -> 16216 Nov 6 09:19:12 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_tail_offset 19048 -> 16216 Nov 6 09:22:13 hill dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: start_offset (20092) > current sync_offset (16532) Nov 6 09:22:13 hill dovecot: IMAP(walbyjon): fscking index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index Nov 6 09:22:13 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_head_offset 20092 -> 16532 Nov 6 09:22:13 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_tail_offset 20092 -> 16532 Nov 6 09:46:47 hill dovecot: IMAP(walbyjon): /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: start_offset (21400) > current sync_offset (17768) Nov 6 09:46:47 hill dovecot: IMAP(walbyjon): fscking index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index Nov 6 09:46:47 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_head_offset 21400 -> 17768 Nov 6 09:46:47 hill dovecot: IMAP(walbyjon): Fixed index file /home/walbyjon/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_tail_offset 21400 -> 17768 Nov 6 14:42:43 hill dovecot: IMAP(jelneckt): /home/jelneckt/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: start_offset (27068) > current sync_offset (26160) Nov 6 14:42:43 hill dovecot: IMAP(jelneckt): fscking index file /home/jelneckt/Maildir/dovecot/public/indexes/decs/.support/dovecot.index Nov 6 14:42:43 hill dovecot: IMAP(jelneckt): Fixed index file /home/jelneckt/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_head_offset 27068 -> 26160 Nov 6 14:42:43 hill dovecot: IMAP(jelneckt): Fixed index file /home/jelneckt/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_tail_offset 27068 -> 26160 Nov 6 14:44:13 hill dovecot: IMAP(jelneckt): /home/jelneckt/Maildir/dovecot/public/indexes/decs/.support/dovecot.index.log: start_offset (28472) > current sync_offset (26984) Nov 6 14:44:13 hill dovecot: IMAP(jelneckt): fscking index file /home/jelneckt/Maildir/dovecot/public/indexes/decs/.support/dovecot.index Nov 6 14:44:13 hill dovecot: IMAP(jelneckt): Fixed index file /home/jelneckt/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_head_offset 28472 -> 26984 Nov 6 14:44:13 hill dovecot: IMAP(jelneckt): Fixed index file /home/jelneckt/Maildir/dovecot/public/indexes/decs/.support/dovecot.index: log_file_tail_offset 28472 -> 26984 Nov 6 14:48:14 hill dovecot: IMAP(jelneckt): Transaction log got desynced for index /home/jelneckt/Maildir/dovecot/public/indexes/decs/.support/dovecot.index Nov 6 14:48:14 hill dovecot: IMAP(jelneckt): Disconnected: Mailbox is in inconsistent state, please relogin. bytes=16540/100499
participants (2)
-
Adam McDougall
-
Timo Sirainen