[Dovecot] 1.2.6 Spurious pread()/stream errors/index corruption

[Paul Freeman]

Hi, 

 We're currently testing 1.2.x with a move from 1.1.x in mind however with
the current 1.2 series we are encountering some serious problems. simply
editing the main conf and restarting dovecot gives these errors seemingly
randomly:

(some previous posts indicated this might be todo with 64bit file offsets
so we've played around with disable-largefile and setting _FILE_OFFSET_BITS
manually but without any success)

---- error while reading main dovecot conf file

Unexpected eof found when reading file 'UNOPENED' (Errcode: -1)
Panic: file istream-file.c: line 80 (i_stream_file_read): assertion
failed: (errno != 0)
Error: Raw backtrace: /NOC4/dovecot/sbin/dovecot [0x41ad42] ->
/NOC4/dovecot/sbin/dovecot(default_fatal_handler+0x34) [0x41ae54] ->
/NOC4/dovecot/sbin/dovecot [0x41a486] -> /NOC4/dovecot/sbin/dovecot
[0x41d9b0] -> /NOC4/dovecot/sbin/dovecot(i_stream_read+0x4c) [0x41cbbc] ->
/NOC4/dovecot/sbin/dovecot(i_stream_read_next_line+0x28) [0x41d408] ->
/NOC4/dovecot/sbin/dovecot(settings_read+0x129) [0x4174d9] ->
/NOC4/dovecot/sbin/dovecot(master_settings_read+0x89) [0x4155a9] ->
/NOC4/dovecot/sbin/dovecot(main+0x1d2) [0x413162] ->
/lib/libc.so.6(__libc_start_main+0xe6) [0x2b6b8258c5c6] ->
/NOC4/dovecot/sbin/dovecot [0x40aec9]


---- when we do get past this error it surfaces again inside the imap
process:

Oct 15 09:40:25 10.0.1.2 dovecot: Dovecot v1.2.6 starting up (core dumps
disabled)
Oct 15 09:40:25 10.0.1.2 dovecot: auth-worker(default): mysql: Connected
to x.x.x.x (Services)
Oct 15 09:40:38 10.0.1.2 dovecot: imap-login: Login: user=<paul at noc4.net>,
method=PLAIN, rip=192.168.167.4, lip=10.0.1.2
Oct 15 09:40:38 10.0.1.2 dovecot: IMAP(paul at noc4.net): Effective uid=512,
gid=512, home=/nmail/noc4/cache
Oct 15 09:40:38 10.0.1.2 dovecot: IMAP(paul at noc4.net): maildir: data=~/
Oct 15 09:40:38 10.0.1.2 dovecot: IMAP(paul at noc4.net): maildir++:
root=/nmail/noc4/cache, index=, control=, inbox=/nmail/noc4/cache
Oct 15 09:40:38 10.0.1.2 dovecot: IMAP(paul at noc4.net): Namespace : Using
permissions from /nmail/noc4/cache: mode=0700 gid=-1
Oct 15 09:40:38 10.0.1.2 dovecot: IMAP(paul at noc4.net): Corrupted
transaction log file /nmail/noc4/cache/dovecot.index.log seq 2: unexpected
end of file while reading header (sync_offset=0)
Oct 15 09:40:59 10.0.1.2 dovecot: IMAP(paul at noc4.net): Unexpected eof
found when reading file 'UNOPENED' (Errcode: -1)
Oct 15 09:40:59 10.0.1.2 dovecot: IMAP(paul at noc4.net): pread() failed with
file /nmail/noc4/cache/dovecot.index.log: Success
Oct 15 09:40:59 10.0.1.2 dovecot: IMAP(paul at noc4.net): Unexpected eof
found when reading file 'UNOPENED' (Errcode: -1)
Oct 15 09:40:59 10.0.1.2 dovecot: IMAP(paul at noc4.net): pread() failed with
file /nmail/noc4/cache/dovecot.index.log: Success
Oct 15 09:40:59 10.0.1.2 dovecot: IMAP(paul at noc4.net): Unexpected eof
found when reading file 'UNOPENED' (Errcode: -1)
Oct 15 09:40:59 10.0.1.2 dovecot: IMAP(paul at noc4.net): pread() failed with
file /nmail/noc4/cache/dovecot.index.log: Success
Oct 15 09:43:18 10.0.1.2 dovecot: IMAP(paul at noc4.net): Server shutting
down bytes=11746/855


---- test with different INDEX location

Oct 15 09:43:20 10.0.1.2 dovecot: Dovecot v1.2.6 starting up (core dumps
disabled)
Oct 15 09:43:20 10.0.1.2 dovecot: auth-worker(default): mysql: Connected
to x.x.x.x (Services)
Oct 15 09:43:30 10.0.1.2 dovecot: IMAP(paul at noc4.net): Effective uid=512,
gid=512, home=/nmail/noc4/cache
Oct 15 09:43:30 10.0.1.2 dovecot: IMAP(paul at noc4.net): maildir:
data=~/:INDEX=/nmail/.Indexes/paul at noc4.net
Oct 15 09:43:30 10.0.1.2 dovecot: IMAP(paul at noc4.net): maildir++:
root=/nmail/noc4/cache, index=/nmail/.Indexes/paul at noc4.net, control=,
inbox=/nmail/noc4/cache
Oct 15 09:43:30 10.0.1.2 dovecot: imap-login: Login: user=<paul at noc4.net>,
method=PLAIN, rip=192.168.167.4, lip=10.0.1.2
Oct 15 09:43:30 10.0.1.2 dovecot: IMAP(paul at noc4.net): Namespace : Using
permissions from /nmail/noc4/cache: mode=0700 gid=-1
Oct 15 09:43:30 10.0.1.2 dovecot: IMAP(paul at noc4.net): Unexpected eof
found when reading file 'UNOPENED' (Errcode: -1)
Oct 15 09:43:30 10.0.1.2 dovecot: IMAP(paul at noc4.net): Panic: file
istream-file.c: line 80 (i_stream_file_read): assertion failed: (errno !=
0)
Oct 15 09:43:31 10.0.1.2 dovecot: IMAP(paul at noc4.net): Raw backtrace: imap
[0x4a6642] -> imap [0x4a66c3] -> imap [0x4a5d86] -> imap [0x4ace20] ->
imap(i_stream_read+0x4c) [0x4ab0dc] -> imap(i_stream_read_next_line+0x28)
[0x4ab928] -> imap(maildir_uidlist_refresh+0x183) [0x443b23] -> imap
[0x440d28] -> imap(maildir_storage_sync_init+0x148) [0x441208] ->
imap(mailbox_sync+0x30) [0x46ce00] -> imap(cmd_select_full+0x383)
[0x4210e3] -> imap [0x42392c] -> imap [0x4239ce] ->
imap(client_handle_input+0x45) [0x423b95] -> imap(client_input+0x5f)
[0x42458f] -> imap(io_loop_handler_run+0xcb) [0x4ae6cb] ->
imap(io_loop_run+0x18) [0x4adb48] -> imap(main+0x537) [0x42c587] ->
/lib/libc.so.6(__libc_start_main+0xe6) [0x2b5edbbdb5c6] -> imap [0x41c699]
Oct 15 09:43:31 10.0.1.2 dovecot: dovecot: child 30298 (imap) killed with
signal 6 (core dumps disabled)


---- our build & test host is

Using built-in specs.
Target: x86_64-pc-linux-gnu
Configured with:
/var/tmp/portage/sys-devel/gcc-4.3.2-r3/work/gcc-4.3.2/configure
--prefix=/usr --bindir=/usr/x86_64-pc-linux-gnu/gcc-bin/4.3.2
--includedir=/usr/lib/gcc/x86_64-pc-linux-gnu/4.3.2/include
--datadir=/usr/share/gcc-data/x86_64-pc-linux-gnu/4.3.2
--mandir=/usr/share/gcc-data/x86_64-pc-linux-gnu/4.3.2/man
--infodir=/usr/share/gcc-data/x86_64-pc-linux-gnu/4.3.2/info
--with-gxx-include-dir=/usr/lib/gcc/x86_64-pc-linux-gnu/4.3.2/include/g++-v4
--host=x86_64-pc-linux-gnu --build=x86_64-pc-linux-gnu --disable-altivec
--disable-fixed-point --enable-nls --without-included-gettext
--with-system-zlib --disable-checking --disable-werror --enable-secureplt
--enable-multilib --enable-libmudflap --disable-libssp --enable-libgomp
--disable-libgcj --enable-languages=c,c++,treelang,fortran --enable-shared
--enable-threads=posix --enable-__cxa_atexit --enable-clocale=gnu
--with-bugurl=http://bugs.gentoo.org/ --with-pkgversion='Gentoo 4.3.2-r3
p1.6, pie-10.1.5'
Thread model: posix
gcc version 4.3.2 (Gentoo 4.3.2-r3 p1.6, pie-10.1.5) 


any input graciously accepted

Regards
  Paul