dovecot - Nov 2009 - Seeing "Corrupted transaction log file" error messages.

In V1.1.15 that I fell back to.  Again:

# 1.1.15: /usr/local/etc/dovecot.conf
# OS: AIX 3 0001378F4C00  
listen: *:143
ssl_listen: *:993
disable_plaintext_auth: no
verbose_ssl: yes
login_dir: /var/run/dovecot/login
login_executable: /usr/local/libexec/dovecot/imap-login
login_processes_count: 12
login_max_processes_count: 774
max_mail_processes: 1024
verbose_proctitle: yes
first_valid_uid: 200
mail_location: mbox:~/mail:INBOX=/var/spool/mail/%u:INDEX=/var/dcindx/%u
mbox_write_locks: fcntl
mbox_dirty_syncs: no
auth default:
  passdb:
    driver: pam
  userdb:
    driver: passwd

This is happening during peak load; the error msgs I'm seeing look like:

Nov  5 15:01:47 mercury mail:err|error dovecot: IMAP(olson): Corrupted
transaction log file /var/dci
ndx/olson/.imap/INBOX/dovecot.index.log seq 742: file_seq=742, min_file_offset
(24) < hdr_size (40)
(sync_offset=24)
Nov  5 15:04:13 mercury mail:err|error dovecot: IMAP(herchenr): Corrupted
transaction log file /var/
dcindx/herchenr/.imap/INBOX/dovecot.index.log seq 357: file_seq=357,
min_file_offset (24) < hdr_size
 (40) (sync_offset=24)
Nov  5 15:04:13 mercury mail:info dovecot: IMAP(herchenr): Disconnected:
Internal error occurred. Re
fer to server log for more information. [2009-11-05 15:04:13] bytes=1314/18024
Nov  5 15:04:33 mercury mail:err|error dovecot: IMAP(olson): Transaction log
file /var/dcindx/olson/
.imap/INBOX/dovecot.index.log: marked corrupted
Nov  5 15:06:17 mercury mail:err|error dovecot: IMAP(olson): Corrupted
transaction log file /var/dci
ndx/olson/.imap/INBOX/dovecot.index.log seq 742: file_seq=742, min_file_offset
(24) < hdr_size (40)
(sync_offset=24)
Nov  5 15:06:17 mercury mail:err|error dovecot: IMAP(olson): Transaction log got
desynced for index
/var/dcindx/olson/.imap/INBOX/dovecot.index

Is worrisome or inconsequential?  About 40 such messages in 30 minutes, 
mostly clumped together
-- 
==== Once upon a time, the Internet was a friendly, 
neighbors-helping-neighbors small town, and no one locked their doors. 
Now it's like an apartment in Bed-Stuy: you need three heavy duty 
pick-proof locks, one of those braces that goes from the lock to the 
floor, and bars on the windows.... ==== Stewart Dean, Unix System Admin, 
Bard College, New York 12504 sdean at bard.edu voice: 845-758-7475, fax: 
845-758-7035

These may be happening to people with big (250MB) mbox folders

Stewart Dean wrote:
> In V1.1.15 that I fell back to.  Again:
>
> # 1.1.15: /usr/local/etc/dovecot.conf
> # OS: AIX 3 0001378F4C00  listen: *:143
> ssl_listen: *:993
> disable_plaintext_auth: no
> verbose_ssl: yes
> login_dir: /var/run/dovecot/login
> login_executable: /usr/local/libexec/dovecot/imap-login
> login_processes_count: 12
> login_max_processes_count: 774
> max_mail_processes: 1024
> verbose_proctitle: yes
> first_valid_uid: 200
> mail_location: mbox:~/mail:INBOX=/var/spool/mail/%u:INDEX=/var/dcindx/%u
> mbox_write_locks: fcntl
> mbox_dirty_syncs: no
> auth default:
>  passdb:
>    driver: pam
>  userdb:
>    driver: passwd
>
> This is happening during peak load; the error msgs I'm seeing look
like:
>
> Nov  5 15:01:47 mercury mail:err|error dovecot: IMAP(olson): Corrupted 
> transaction log file /var/dci
> ndx/olson/.imap/INBOX/dovecot.index.log seq 742: file_seq=742, 
> min_file_offset (24) < hdr_size (40) (sync_offset=24)
> Nov  5 15:04:13 mercury mail:err|error dovecot: IMAP(herchenr): 
> Corrupted transaction log file /var/
> dcindx/herchenr/.imap/INBOX/dovecot.index.log seq 357: file_seq=357, 
> min_file_offset (24) < hdr_size
> (40) (sync_offset=24)
> Nov  5 15:04:13 mercury mail:info dovecot: IMAP(herchenr): 
> Disconnected: Internal error occurred. Re
> fer to server log for more information. [2009-11-05 15:04:13] 
> bytes=1314/18024
> Nov  5 15:04:33 mercury mail:err|error dovecot: IMAP(olson): 
> Transaction log file /var/dcindx/olson/
> .imap/INBOX/dovecot.index.log: marked corrupted
> Nov  5 15:06:17 mercury mail:err|error dovecot: IMAP(olson): Corrupted 
> transaction log file /var/dci
> ndx/olson/.imap/INBOX/dovecot.index.log seq 742: file_seq=742, 
> min_file_offset (24) < hdr_size (40) (sync_offset=24)
> Nov  5 15:06:17 mercury mail:err|error dovecot: IMAP(olson): 
> Transaction log got desynced for index 
> /var/dcindx/olson/.imap/INBOX/dovecot.index
>
> Is worrisome or inconsequential?  About 40 such messages in 30 
> minutes, mostly clumped together
-- 
==== Once upon a time, the Internet was a friendly, 
neighbors-helping-neighbors small town, and no one locked their doors. 
Now it's like an apartment in Bed-Stuy: you need three heavy duty 
pick-proof locks, one of those braces that goes from the lock to the 
floor, and bars on the windows.... ==== Stewart Dean, Unix System Admin, 
Bard College, New York 12504 sdean at bard.edu voice: 845-758-7475, fax: 
845-758-7035

On Thu, 2009-11-05 at 15:22 -0500, Stewart Dean wrote:
> In V1.1.15 that I fell back to.  Again:
> Nov  5 15:01:47 mercury mail:err|error dovecot: IMAP(olson): Corrupted
transaction log file /var/dci
> ndx/olson/.imap/INBOX/dovecot.index.log seq 742: file_seq=742,
min_file_offset (24) < hdr_size (40)
> (sync_offset=24)
This means that dovecot.index.log was created by Dovecot v1.2, because
header size is 40. Then you went back to v1.1 which has header size 24.
This should have worked, but apparently there's some bug that caused
Dovecot to try to start reading the .log file from offset 24 instead of
40.

Would be nice to find and fix this bug, but seems like a bit too much
trouble and this problem fixes itself automatically anyway.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 197 bytes
Desc: This is a digitally signed message part
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20091105/ccc7ce2f/attachment-0002.bin>