[Dovecot] Bad file descriptor with maildir and bzip2 files
Hi,
I'm using the zlib plugin with dovecot 1.1.2 (on Centos 4.5, x86, ext3) and some bzip2 (version 1.0.2) compressed mail files are causing the following error to show in the logs when I click on the folder in outlook express.
Aug 27 11:39:15 server-2 dovecot: IMAP(marchive): fstat(maildir) failed: Bad file descriptor
Aug 27 11:39:17 Info: IMAP(marchive): Loading modules from directory: /usr/local/lib/dovecot/imap/ Aug 27 11:39:17 Info: IMAP(marchive): Module loaded: /usr/local/lib/dovecot/imap//lib20_zlib_plugin.so Aug 27 11:39:17 Info: IMAP(marchive): Effective uid=606, gid=609, home=/home/marchive Aug 27 11:39:17 Info: IMAP(marchive): maildir: data=/var/spool/maildir/marchive Aug 27 11:39:17 Info: IMAP(marchive): maildir++: root=/var/spool/maildir/marchive, index=, control=, inbox=/var/spool/maildir/marchive Aug 27 11:39:18 Info: IMAP(marchive): Disconnected: Internal error occurred. Refer to server log for more information. [20 08-08-27 11:39:18] bytes=246/1040
I attached strace to it and got the following: 11:39:18.193667 open("/var/spool/maildir/marchive/.2003.INBOX.Charlie.Old.OldInbox.2004/cur/1169027932.P30745Q17M499928.server-2:2,S=103418,Z", O_RDONLY|O_LARGEFILE) = 11 11:39:18.194130 fstat64(11, {st_mode=S_IFREG|0644, st_size=47637, ...}) = 0 11:39:18.194494 pread64(11, "BZh91AY&SY\231\206Z\257\0S\360\377\200\177\3746,U\357\377\377\377\377\377\360\277"..., 4096, 0) = 4096 11:39:18.200204 dup(11) = 12 11:39:18.200557 close(11) = 0 11:39:18.200916 fcntl64(12, F_GETFL) = 0x8000 (flags O_RDONLY|O_LARGEFILE) 11:39:18.200971 fstat64(12, {st_mode=S_IFREG|0644, st_size=47637, ...}) = 0 11:39:18.201104 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7ff2000 11:39:18.201216 _llseek(12, 0, [0], SEEK_CUR) = 0 11:39:18.201355 fstat64(12, {st_mode=S_IFREG|0644, st_size=47637, ...}) = 0 11:39:18.201478 brk(0x9e61000) = 0x9e61000 11:39:18.201612 read(12, "BZh91AY&SY\231\206Z\257\0S\360\377\200\177\3746,U\357\377\377\377\377\377\360\277"..., 4096) = 4096 11:39:18.201694 read(12, "\277\217\261\0g!\273\')/3\343V\336\276}\273/\210I\26^\255\304\323\r\275Wts\3773"..., 4096) = 4096 11:39:18.201793 mmap2(NULL, 3600384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7c68000 11:39:18.205993 read(12, "~\214\261E*@[\200\245\302\232\201\334\331\272\225NQ\244\260\371\3473cc\312\255\326\246\17\'\222"..., 4096) = 4096 < continues reading from the file > 11:39:18.225970 read(12, "+:E\225\7\217W\264\367\27\226\262i9\34\227=\350\250BcmF\306\'\231m\265\233\337\343\237"..., 4096) = 2581 11:39:18.226040 read(12, "", 4096) = 0 < 26x more of this read > 11:39:18.233913 munmap(0xb7c68000, 3600384) = 0 11:39:18.234070 close(12) = 0 11:39:18.234120 munmap(0xb7ff2000, 4096) = 0 11:39:18.234184 fcntl64(12, F_GETFL) = -1 EBADF (Bad file descriptor) 11:39:18.234255 fstat64(12, 0xbff0a9a0) = -1 EBADF (Bad file descriptor) 11:39:18.234347 write(2, "\1Efstat(maildir) failed: Bad fil"..., 45) = 45
To me it looks like its trying to call fcntl on the handle its just closed?
I've since decompressed these files and recompressed with "gzip -9" and they seem to be opening OK.
dovecot -n gives: # 1.1.2: /usr/local/etc/dovecot.conf info_log_path: /var/log/dovecot.log protocols: imap imaps pop3 ssl_disable: yes disable_plaintext_auth: no login_dir: /usr/local/var/run/dovecot/login login_executable(default): /usr/local/libexec/dovecot/imap-login login_executable(imap): /usr/local/libexec/dovecot/imap-login login_executable(pop3): /usr/local/libexec/dovecot/pop3-login mail_location: maildir:/var/spool/maildir/%u mail_debug: yes mail_executable(default): /usr/local/libexec/dovecot/imap mail_executable(imap): /usr/local/libexec/dovecot/imap mail_executable(pop3): /usr/local/libexec/dovecot/pop3 mail_plugins: zlib mail_plugin_dir(default): /usr/local/lib/dovecot/imap/ mail_plugin_dir(imap): /usr/local/lib/dovecot/imap/ mail_plugin_dir(pop3): /usr/local/lib/dovecot/pop3/ imap_client_workarounds(default): delay-newmail imap_client_workarounds(imap): delay-newmail imap_client_workarounds(pop3): pop3_client_workarounds(default): pop3_client_workarounds(imap): pop3_client_workarounds(pop3): outlook-no-nuls auth default: passdb: driver: pam userdb: driver: passwd
ChrisB.
On Aug 27, 2008, at 6:39 PM, Chris Burton wrote:
Hi,
I'm using the zlib plugin with dovecot 1.1.2 (on Centos 4.5, x86,
ext3) and some bzip2 (version 1.0.2) compressed mail files are
causing the following error to show in the logs when I click on the
folder in outlook express.Aug 27 11:39:15 server-2 dovecot: IMAP(marchive): fstat(maildir)
failed: Bad file descriptor
See if this helps: http://hg.dovecot.org/dovecot-1.1/rev/e024baa42a4f
Hi, Thanks for the quick reply - it didn't work as is (caused the same error), here's what the strace looks like with your patch.
19:34:20.233363 read(12, "", 4096) = 0 19:34:20.233455 dup(12) = 11 19:34:20.233540 munmap(0xb7bd8000, 3600384) = 0 19:34:20.233909 close(12) = 0 19:34:20.233986 munmap(0xb7f62000, 4096) = 0 19:34:20.234088 fcntl64(11, F_GETFL) = 0x8000 (flags O_RDONLY|O_LARGEFILE) 19:34:20.234169 fstat64(11, {st_mode=S_IFREG|0644, st_size=170988, ...}) = 0 19:34:20.234563 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f62000 19:34:20.234646 _llseek(11, 0, [170988], SEEK_CUR) = 0 19:34:20.234765 fstat64(12, 0xbfea37d0) = -1 EBADF (Bad file descriptor) 19:34:20.234986 write(2, "\1Efstat(maildir) failed: Bad fil"..., 45) = 45
I took a look at the code and the logic being different depending on HAVE_GZSEEK didn't seem right so I tried adding a "else" before the "#else" and recompiled and it's working now with the same bzip2 files that caused the problem previously.
I'm not sure if that's a fluke or a fix though :).
ChrisB.
On Wed, 2008-08-27 at 19:45 +0100, Chris Burton wrote:
Hi, Thanks for the quick reply - it didn't work as is (caused the same error), here's what the strace looks like with your patch.
19:34:20.233363 read(12, "", 4096) = 0 19:34:20.233455 dup(12) = 11 19:34:20.233540 munmap(0xb7bd8000, 3600384) = 0 19:34:20.233909 close(12) = 0 19:34:20.233986 munmap(0xb7f62000, 4096) = 0 19:34:20.234088 fcntl64(11, F_GETFL) = 0x8000 (flags O_RDONLY|O_LARGEFILE) 19:34:20.234169 fstat64(11, {st_mode=S_IFREG|0644, st_size=170988, ...}) = 0 19:34:20.234563 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f62000 19:34:20.234646 _llseek(11, 0, [170988], SEEK_CUR) = 0 19:34:20.234765 fstat64(12, 0xbfea37d0) = -1 EBADF (Bad file descriptor) 19:34:20.234986 write(2, "\1Efstat(maildir) failed: Bad fil"..., 45) = 45
How about after this: http://hg.dovecot.org/dovecot-1.1/rev/c83a677ce80b
I took a look at the code and the logic being different depending on HAVE_GZSEEK didn't seem right so I tried adding a "else" before the "#else" and recompiled and it's working now with the same bzip2 files that caused the problem previously.
I'm not sure if that's a fluke or a fix though :).
Don't do that, it'll break it, at least in some situations.
How about after this: http://hg.dovecot.org/dovecot-1.1/rev/c83a677ce80b
Thanks it's working great now with your patch (I'll upgrade to 1.1.3 shortly).
Also just to let you know I've now compressed the maildir (a split of gzip/bzip2 depending on which saved the most) which has reduced it from 38GB to 23GB with some 1.8MB files being compressed down to 36KB (emailed tiff files don't ask) which saves a lot in disk access as well as disk space.
Thanks, ChrisB.
On 9/2/2008, Chris Burton (Chris@7of9b.org) wrote:
Also just to let you know I've now compressed the maildir (a split of gzip/bzip2 depending on which saved the most) which has reduced it from 38GB to 23GB with some 1.8MB files being compressed down to 36KB (emailed tiff files don't ask) which saves a lot in disk access as well as disk space.
wow... but I wonder what the cost is in performance?
--
Best regards,
Charles
On 9/2/2008, Chris Burton (Chris@7of9b.org) wrote:
Also just to let you know I've now compressed the maildir (a split of gzip/bzip2 depending on which saved the most) which has reduced it from 38GB to 23GB with some 1.8MB files being compressed down to 36KB (emailed tiff files don't ask) which saves a lot in disk access as well as disk space.
wow... but I wonder what the cost is in performance?
Most of the mail compressed was from 2001-2007 and has been moved into an "archive" mail account which only 2/3 people currently have access to and I can't see it getting that much use so performance was of little concern in this instance.
ChrisB.
participants (3)
-
Charles Marcus
-
Chris Burton
-
Timo Sirainen