[Dovecot] Imap assertion (dovecot-1.1.beta13)
Hi, I continue testing the beta versions and have seen a great improvement over the last few ones. On beta13 I'm seeing the following assert on some client folders: file index-mail.c: line 759 (index_mail_stream_destroy_callback): assertion failed: (mail->data.destroying_stream)
If you need I can try and reproduce this in a more controled environment to pinpoint the problem.
Thanks,
Nuno Lopes
On Mon, 2008-01-07 at 15:38 +0000, Nuno Lopes wrote:
Hi, I continue testing the beta versions and have seen a great improvement over the last few ones. On beta13 I'm seeing the following assert on some client folders: file index-mail.c: line 759 (index_mail_stream_destroy_callback): assertion failed: (mail->data.destroying_stream)
If you need I can try and reproduce this in a more controled environment to pinpoint the problem.
A few people have now reported this, but I haven't managed to reproduce it myself. So it would be nice if someone told me how..
Timo Sirainen wrote:
On Mon, 2008-01-07 at 15:38 +0000, Nuno Lopes wrote:
Hi, I continue testing the beta versions and have seen a great improvement over the last few ones. On beta13 I'm seeing the following assert on some client folders: file index-mail.c: line 759 (index_mail_stream_destroy_callback): assertion failed: (mail->data.destroying_stream)
If you need I can try and reproduce this in a more controled environment to pinpoint the problem.
A few people have now reported this, but I haven't managed to reproduce it myself. So it would be nice if someone told me how..
Sorry, missed those. So here goes some more detail:
this happens when I connect to a folder (in my case Sent). I've reproduced the bug by sending the following commands directly to the imap server:
<authentication> 3 select "Sent" 4 getquotaroot "Sent" 5 UID fetch 1:* (FLAGS) 6 UID fetch 1:201 (UID RFC822.SIZE FLAGS BODY.PEEK[HEADER.FIELDS (From To Cc Subject Date Message-ID Priority X-Priority References Newsgroups In-Reply-To Content-Type)])
then the server crashes. Attached you can find an strace log made after command 5. If you need any more detail I'll be glad to give it ...
Hope this helps,
Nuno Lopes
03:42:42.009485 gettimeofday({1199763762, 9719}, {0, 0}) = 0 03:42:42.009773 gettimeofday({1199763762, 9790}, NULL) = 0 03:42:42.009828 poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 2, 1729) = 0 03:42:43.754391 gettimeofday({1199763763, 754415}, {0, 0}) = 0 03:42:43.754460 gettimeofday({1199763763, 754472}, NULL) = 0 03:42:43.754508 poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 2, 5000) = 0 03:42:48.769219 gettimeofday({1199763768, 769268}, {0, 0}) = 0 03:42:48.769322 gettimeofday({1199763768, 769337}, NULL) = 0 03:42:48.769370 poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}], 2, 2559) = 0 03:42:51.340389 gettimeofday({1199763771, 340414}, {0, 0}) = 0 03:42:51.340460 gettimeofday({1199763771, 340472}, NULL) = 0 03:42:51.340508 poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL}, {fd=0, events=POLLIN|POLLPRI|POLLERR|POLLHUP|POLLNVAL, revents=POLLIN}], 2, 2429) = 1 03:42:51.842406 gettimeofday({1199763771, 842433}, {0, 0}) = 0 03:42:51.842483 read(0, "6 UID fetch 1:201 (UID RFC822.SI"..., 4031) = 172 03:42:51.842798 open("portugalmail.pt/ob/mnuno.lopes/.Sent/dovecot.index.cache", O_RDWR|O_LARGEFILE) = 10 03:42:51.843662 fstat64(10, {st_mode=S_IFREG|0600, st_size=15857, ...}) = 0 03:42:51.843826 mmap2(NULL, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40149000 03:42:51.843893 pread(10, "\1\10\0\0^F\202G\225G\202G\0\0\0\0\0\0\0\0,\1\0\0\0\0\0"..., 4096, 0) = 4096 03:42:51.843999 pread(10, "\0\0\0\0\351\0\0\0\n\0\0\0", 12, 32) = 12 03:42:51.844066 pread(10, "\1\10\0\0^F\202G\225G\202G\0\0\0\0\0\0\0\0,\1\0\0\0\0\0"..., 4096, 0) = 4096 03:42:51.844203 open("portugalmail.pt/ob/mnuno.lopes/.Sent/cur/1083034619.20947_0.frodo,S=410:2,S", O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory) 03:42:51.845149 umask(0177) = 077 03:42:51.845198 time(NULL) = 1199763771 03:42:51.845247 lstat64("portugalmail.pt/ob/mnuno.lopes/.Sent/dovecot-uidlist.lock", 0xbfffeee0) = -1 ENOENT (No such file or directory) 03:42:51.845584 open("portugalmail.pt/ob/mnuno.lopes/.Sent/dovecot-uidlist.lock", O_RDWR|O_CREAT|O_EXCL|O_LARGEFILE, 0666) = 11 03:42:51.849987 write(11, "19464:eowyn", 11) = 11 03:42:51.850048 fstat64(11, {st_mode=S_IFREG|0600, st_size=11, ...}) = 0 03:42:51.850188 close(11) = 0 03:42:51.852372 lstat64("portugalmail.pt/ob/mnuno.lopes/.Sent/dovecot-uidlist.lock", {st_mode=S_IFREG|0600, st_size=11, ...}) = 0 03:42:51.852546 umask(077) = 0177 03:42:51.852592 stat64("portugalmail.pt/ob/mnuno.lopes/.Sent", {st_mode=S_IFDIR|0700, st_size=496, ...}) = 0 03:42:51.852722 chown32(0x8104458, 0x1f5, 0xffffffff) = 0 03:42:51.853368 open("portugalmail.pt/ob/mnuno.lopes/.Sent/dovecot-uidlist", O_RDONLY|O_LARGEFILE) = 11 03:42:51.853455 close(11) = 0 03:42:51.853496 stat64("portugalmail.pt/ob/mnuno.lopes/.Sent/dovecot-uidlist", {st_mode=S_IFREG|0600, st_size=10763, ...}) = 0 03:42:51.853638 fstat64(8, {st_mode=S_IFREG|0600, st_size=10763, ...}) = 0 03:42:51.853818 brk(0x814b000) = 0x814b000 03:42:51.853908 alarm(180) = 0 03:42:51.853961 fcntl64(6, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}, 0xbffff070) = 0 03:42:51.854715 alarm(0) = 180 03:42:51.854835 stat64("portugalmail.pt/ob/mnuno.lopes/.Sent", {st_mode=S_IFDIR|0700, st_size=496, ...}) = 0 03:42:51.855149 chown32(0x8104490, 0x1f5, 0xffffffff) = 0 03:42:51.856022 stat64("portugalmail.pt/ob/mnuno.lopes/.Sent/dovecot.index.log", {st_mode=S_IFREG|0600, st_size=2168, ...}) = 0 03:42:51.856678 pread(6, "", 1024, 2168) = 0 03:42:51.856843 open("portugalmail.pt/ob/mnuno.lopes/.Sent/new", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 11 03:42:51.857005 fstat64(11, {st_mode=S_IFDIR|0700, st_size=48, ...}) = 0 03:42:51.857166 fcntl64(11, F_SETFD, FD_CLOEXEC) = 0 03:42:51.857261 fstat64(11, {st_mode=S_IFDIR|0700, st_size=48, ...}) = 0 03:42:51.857418 time(NULL) = 1199763771 03:42:51.857535 getdents64(11, /* 2 entries */, 4096) = 48 03:42:51.857681 getdents64(11, /* 0 entries */, 4096) = 0 03:42:51.857763 close(11) = 0 03:42:51.857861 open("portugalmail.pt/ob/mnuno.lopes/.Sent/cur", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 11 03:42:51.858038 fstat64(11, {st_mode=S_IFDIR|0700, st_size=13672, ...}) = 0 03:42:51.858225 fcntl64(11, F_SETFD, FD_CLOEXEC) = 0 03:42:51.858285 fstat64(11, {st_mode=S_IFDIR|0700, st_size=13672, ...}) = 0 03:42:51.858432 time(NULL) = 1199763771 03:42:51.858505 getdents64(11, /* 56 entries */, 4096) = 4056 03:42:51.862437 getdents64(11, /* 57 entries */, 4096) = 4096 03:42:51.865975 getdents64(11, /* 55 entries */, 4096) = 4040 03:42:51.869433 getdents64(11, /* 35 entries */, 4096) = 2488 03:42:51.871549 getdents64(11, /* 0 entries */, 4096) = 0 03:42:51.871666 close(11) = 0 03:42:51.871960 fcntl64(6, F_SETLK64, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}, 0xbffff150) = 0 03:42:51.872289 lstat64("portugalmail.pt/ob/mnuno.lopes/.Sent/dovecot-uidlist.lock", {st_mode=S_IFREG|0600, st_size=11, ...}) = 0 03:42:51.872514 unlink("portugalmail.pt/ob/mnuno.lopes/.Sent/dovecot-uidlist.lock") = 0 03:42:51.874553 open("portugalmail.pt/ob/mnuno.lopes/.Sent/cur/1083034619.20947_0.frodo,S=410:2,SZ", O_RDONLY|O_LARGEFILE) = 11 03:42:51.875349 fstat64(11, {st_mode=S_IFREG|0644, st_size=328, ...}) = 0 03:42:51.875505 dup(11) = 12 03:42:51.875560 close(11) = 0 03:42:51.875632 write(2, "\1Pfile index-mail.c: line 759 (i"..., 117) = 117 03:42:51.875769 rt_sigprocmask(SIG_UNBLOCK, [ABRT], NULL, 8) = 0 03:42:51.875964 getpid() = 19464 03:42:51.876046 kill(19464, SIGABRT) = 0 03:42:51.876092 --- SIGABRT (Aborted) @ 0 (0) ---
Hi Timo, I just discovered that this bug is showing up in the folder where I archive this mailing list. I also noticed that this problem is happening on folders where I was trying the zlib plugin for maildirs (introduced in 1.1.beta5). Since this folder hasn't got any confidential mail I can make it publicly available. You can get it from:
- The whole folder (29M) http://celebrian.portugalmail.pt/mail-folder.tgz
- dovecot files (188K) http://celebrian.portugalmail.pt/mail-dovecot.tgz
These files were created after removing all dovecot files and connecting to the folder through thunderbird, sort of a clean start. I hope this can help you in reproducing the problem.
I should also send you some more data:
linux distribution: SLES-9 x86 using nfs
dovecot -n output:
# 1.1.beta13: /opt/dovecot-1.1.beta13/etc/dovecot.conf base_dir: /var/run/dovecot/ protocols: imap listen: *:10143 ssl_disable: yes disable_plaintext_auth: no shutdown_clients: no login_dir: /var/run/dovecot/login login_executable: /opt/dovecot/libexec/dovecot/imap-login login_process_per_connection: no login_max_connections: 400 max_mail_processes: 750 verbose_proctitle: yes mail_uid: 501 mail_gid: 100 mmap_disable: yes mail_nfs_storage: yes mail_nfs_index: yes mail_plugins: quota imap_quota zlib mail_plugin_dir: /opt/dovecot/lib/dovecot/imap auth default: executable: /opt/dovecot/libexec/dovecot/dovecot-auth user: nobody passdb: driver: ldap args: /opt/dovecot/etc/dovecot-ldap.conf userdb: driver: ldap args: /opt/dovecot/etc/dovecot-ldap.conf socket: type: listen master: path: /var/run/dovecot/auth-master mode: 384 user: vmail group: nogroup plugin: quota: maildir quota_rule: *:storage=2G quota_rule2: Trash:storage=102400 quota_rule3: INBOX.Trash:storage=102400
Thanks,
Nuno Lopes
On Thu, 2008-01-10 at 20:46 +0000, Nuno Lopes wrote:
Hi Timo, I just discovered that this bug is showing up in the folder where I archive this mailing list. I also noticed that this problem is happening on folders where I was trying the zlib plugin for maildirs (introduced in 1.1.beta5). Since this folder hasn't got any confidential mail I can make it publicly available. You can get it from:
Thanks, fixed: http://hg.dovecot.org/dovecot/rev/ca223be145b5
Now I just hope other people seeing this assert had the same problem.. :)
participants (2)
-
Nuno Lopes
-
Timo Sirainen