Steffen Kaiser
2007-Mar-21 14:28 UTC
[Dovecot] Unexpected behaviour when deleteing a big mailbox
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Hello, my last tests left me with a mailbox with > 80'000 messages in Maildir. Dovecot served them fine. No problem. I usually use IMAP's "Mark messages a deleted" function and expunge later. Because the "Move to Trash" is default in many MUAs, I decided to try it on this mailbox. I do think that it is hard to detect and prevent such problem, but could it be implemented that when the client connection times out, the COPY process is terminated and rolled back? I mean, as long as the messages are copied/linked to */tmp nothing is done, yet, hence, a simple cleanup of */tmp would result in a rollback. Due to the timeout, the EXPUNGE wasn't issued so far and the source mailbox is unchanged. Or, is it possible to prevent two COPYs of an overlapping message range into the same destination folder simultaneously? Or, can I prevent to COPY such a huge range of messages at once? I know 80'000 messages are much, but I have users with an INBOX of at least 40'000, eventually moving all files into an archive mailbox. I'm also surprised to find that I didn't get two full copies of the source mailbox. ============= Start situation: 4.8G .box1 (I didn't recorded the individual subdirs, unfortunately.) # find .box1 -type f | wc -l 84273 Newly created .Trash. == I started Thunderbird, let sync the mailbox, selected them all, and pressed "Delete". Some time later: Connection timed out. I, wondered, and hit "Delete" a second time. Again, connection timed out. == I was surprised, however, to see that the Dovecot log with still active telling me that mails are copied to Trash. I ended up with two processes copying all messages to .Trash/tmp on the server. The process I traced a bit later linked any file after the other. What I wondered right from the beginning was, that du -hs .??* displayed about 3.5GB in .Trash, but still 4.8GB in .box1. So, why are there 3.5GB additional files in .Trash, when I configured Dovecot to use hardlinks? The end situation is that .box1 contains all messages still, but any Unseen messages are moved to .box1/cur, and .Trash contains: 7.4G .Trash/cur 791M .Trash/new 76K .Trash/tmp # find .Trash/ -type f | wc -l 121713 The size nearly doubled. # du -hs .box1 ; du -sh .Trash/ 4.8G .box1 8.2G .Trash/ === Last lines in Dovecot log: dovecot: Mar 21 11:46:15 Info: IMAP(dvtest) [11535]: copy -> Trash: uid=83964, msgid=<xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx at xx-xxxx-xxxxx-xxxx.xx>, box=box1 dovecot: Mar 21 11:46:15 Info: IMAP(dvtest) [11535]: copy -> Trash: uid=83965, msgid=<xxxxxxxx.xxxxxxx at xx-xxxx-xxxxx-xxxx.xx>, box=box1 dovecot: Mar 21 11:46:29 Info: IMAP(dvtest) [11535]: Disconnected: Mailbox is in inconsistent state, please relogin. Last lines of strace: fstat64(13, {st_mode=S_IFREG|0600, st_size=1341104, ...}) = 0 stat64("/var/cache/dovecot/31045/index/.box1/dovecot.index", {st_mode=S_IFREG|0600, st_size=1341104, ...}) = 0 alarm(120) = 0 fcntl64(13, F_SETLKW64, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}, 0xbfe562d4) = 0 alarm(0) = 120 fstat64(13, {st_mode=S_IFREG|0600, st_size=1341104, ...}) = 0 mmap2(NULL, 1341104, PROT_READ|PROT_WRITE, MAP_SHARED, 13, 0) = 0xb3ffc000 munmap(0xb4285000, 1341104) = 0 write(1, "* 7998 FETCH (FLAGS ($Label2 $La"..., 2067) = 2067 write(1, "* 8091 FETCH (FLAGS (\\Answered \\"..., 2056) = -1 EPIPE (Broken pipe) - --- SIGPIPE (Broken pipe) @ 0 (0) --- munmap(0xb7cbc000, 1341104) = 0 fcntl64(13, F_SETLK64, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}, 0xbfe56394) = 0 write(2, "\1IDisconnected: Mailbox is in in"..., 66) = 66 # /usr/local/dovecot.rc27/sbin/dovecot -n # /usr/local/dovecot.rc27/etc/dovecot.conf base_dir: /var/run/dovecot/ log_path: /var/log/dovecot/dovecot.log protocols: imap imaps pop3 pop3s ssl_ca_file: /etc/ssl/certs/ca.crt ssl_cert_file(default): /etc/ssl/certs/imap.pem ssl_cert_file(imap): /etc/ssl/certs/imap.pem ssl_cert_file(pop3): /etc/ssl/certs/pop3.pem ssl_key_file(default): /etc/ssl/private/imap.key ssl_key_file(imap): /etc/ssl/private/imap.key ssl_key_file(pop3): /etc/ssl/private/pop3.key disable_plaintext_auth: no verbose_ssl: yes login_dir: /var/run/dovecot//login login_executable(default): /usr/local/dovecot.rc27/libexec/dovecot/imap-login login_executable(imap): /usr/local/dovecot.rc27/libexec/dovecot/imap-login login_executable(pop3): /usr/local/dovecot.rc27/libexec/dovecot/pop3-login login_log_format_elements: %p: user=<%u> method=%m rip=%r lip=%l %c verbose_proctitle: yes first_valid_uid: 1000 mail_location: maildir:%h/MailDir:CONTROL=/var/cache/dovecot/%i/control:INDEX=/var/cache/dovecot/%i/index mail_debug: yes dotlock_use_excl: yes maildir_copy_with_hardlinks: yes maildir_copy_preserve_filename: yes mail_drop_priv_before_exec: yes mail_executable(default): /usr/local/dovecot.rc27/libexec/dovecot/imap mail_executable(imap): /usr/local/dovecot.rc27/libexec/dovecot/imap mail_executable(pop3): /usr/local/dovecot.rc27/libexec/dovecot/pop3 mail_plugins(default): quota imap_quota mail_log zlib mail_plugins(imap): quota imap_quota mail_log zlib mail_plugins(pop3): quota mail_log mail_plugin_dir(default): /usr/local/dovecot.rc27/lib/dovecot/imap mail_plugin_dir(imap): /usr/local/dovecot.rc27/lib/dovecot/imap mail_plugin_dir(pop3): /usr/local/dovecot.rc27/lib/dovecot/pop3 mail_log_prefix: %Us(%u) [%p]: mail_log_max_lines_per_sec: 30 pop3_uidl_format(default): pop3_uidl_format(imap): pop3_uidl_format(pop3): %u pop3_client_workarounds(default): pop3_client_workarounds(imap): pop3_client_workarounds(pop3): oe-ns-eoh namespace: type: private separator: . inbox: yes hidden: yes auth default: mechanisms: plain login cache_size: 10 username_chars: abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ01234567890 verbose: yes debug: yes passdb: driver: ldap args: /usr/local/dovecot.rc26/etc/dovecot-ldap.conf passdb: driver: shadow userdb: driver: prefetch userdb: driver: ldap args: /usr/local/dovecot.rc26/etc/dovecot-ldap.conf userdb: driver: passwd-file args: /etc/passwd socket: type: listen client: path: /var/run/dovecot/auth-client mode: 432 master: path: /var/run/dovecot/auth-master mode: 432 group: mail plugin: quota: fs Bye, - -- Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.6 (GNU/Linux) iQEVAwUBRgFBGy9SORjhbDpvAQLBcQf+OAqiufFlyPqJTyM3Ylkmiae2afXPe2wl bNWg6AyDrdvFw+rtdc5vnYukQUSk2a8zQBggt3Rfb1zZQb0pszrzLdR+fOwnW2uE kDyHRhyy88aVpM848oQKYnlWdNHFrdwbyp2myU4JxJhu0bXsAhyMgf9txshwe5cd 23O1x+gkWUp+1wuz84uTep3Kcs1wVXWANEN5RT4YMI3MOqMrcyB+P0lj0luy0HTH HE9T6mLqzGt0Cw6yfm+1W8bU3Wnt3C5je15gT++OPd5YmDvpQs+fOjavDIITsuOf jBck4N+KjwOM+FzP8Ea1WNWCvObJKdeiISkoFWFO9bafw5Yue9hFNA==yyP5 -----END PGP SIGNATURE-----
Steffen Kaiser
2007-Mar-21 15:38 UTC
[Dovecot] Unexpected behaviour when deleteing a big mailbox
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 On Wed, 21 Mar 2007, Steffen Kaiser wrote: Just to add: Without the "mail_log" plugin, the 80'000 message are copied almost in time to Trash; the timeout occured while renaming the files from tmp to cur or new. = I noticed with EXPUNGE that the client feedback is sent after all messages are deleted, when this is the same with COPY, could one sent some feedback to the client in order to keep the connection open? Bye, - -- Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.6 (GNU/Linux) iQEVAwUBRgFRiC9SORjhbDpvAQLKrgf9GBOjl3zK/28wLpRDIKm4On/jxqcKxNKO Cm8yG02uFaS1164rvTZwmEY3wPU1dolJJ9U/49P25NIlRIdXyKhPh4FJh82Ujwtr peMa1g4AM+yn9WLjrPpi5L2RCUUlSYUaoIHHPCJEQipwTjypp8sVPj0RKxBynbrZ J7N5aWwzEhXc4DwT4z5ejqQT21jmiV3VJ2iE48d/JkDSHptJjYslH0VlDEMSxuAF n3wldvB7bfkTDJLQHYP1Jxd98+v9wHMnFsZYyA6hTdUgWY6qm9SV466AflXOpQM4 7uGASJR974ttY6M998ZV8pdY146y7BbmTEEeOfOQg6Q8HGBIYPwGdQ==S6C1 -----END PGP SIGNATURE-----