[Dovecot] dsync on large mailbox "fails"

[Jeff Kletsky]

On 4/23/12 12:56 PM, Jeff Kletsky wrote:
> I've been trying to convert an existing set of mbox mail to maildir 
> using dsync, but it seems to fail when it gets to the large boxes.
>
> $ dsync -Dv mirror maildir:~/Maildir
>
> Everything seems to work reasonably well until the first of the large 
> boxes hits:
>
> dsync(jeff): Warning: Maildir /home/jeff/Maildir/.cron.2010-07-10: 
> Synchronization took 1210 seconds (102289 new msgs, 0 flag change 
> attempts, 0 expunge attempts)
> dsync(jeff): Warning: Transaction log file 
> /home/jeff/Maildir/.cron.2010-07-10/dovecot.index.log was locked for 
> 1210 seconds
>
> After this, the doveadm process goes from ~75% of the CPU core 
> utilization to 100% and stays there, even overnight.
>

I believe that some of problem may be that there were a handful of boxes 
named with "." in them. These were not "flagged" in the conversion 
process in any way.

http://wiki2.dovecot.org/Migration/MailFormat indicates that you can't 
have a "." in the name of a Maildir box

(I dutifully stopped reading that page at "If you can successfully use 
dsync, you can skip the rest of this page.")

In my case, it may be a contributing factor that there were boxes that 
ended up "stacking" inside each other:
* cron
* cron.2010-07-10
* cron.2010-07-10.remaining

Still not blisteringly fast, but

dsync(jeff): Warning: Maildir /home/jeff/Maildir/.cron_2010-07-10: 
Synchronization took 686 seconds (102289 new msgs, 0 flag change 
attempts, 0 expunge attempts)
dsync(jeff): Warning: Transaction log file 
/home/jeff/Maildir/.cron_2010-07-10/dovecot.index.log was locked for 686 
seconds

is certainly better.

I'm still seeing 100% CPU utilization, with the tail of ls -Altr in 
~/Maildir showing

drwx------  5 jeff  jeff   512 Apr 23 18:19 .XDA
drwx------  5 jeff  jeff   512 Apr 23 18:19 .Spam
drwx------  5 jeff  jeff   512 Apr 23 18:42 .Health
drwx------  5 jeff  jeff   512 Apr 23 18:42 .cron_2010-07-10_remaining
drwx------  5 jeff  jeff   512 Apr 23 18:58 .cron_2010-07-10

It appears from looking in the .cron_2010-07-10 directory that indexing 
is the action underway

[jeff at mail ~/Maildir]$ ls -Altr .cron_2010-07-10
total 27
drwx------  2 jeff  jeff      512 Apr 23 18:15 new
-rw-------  1 jeff  jeff        0 Apr 23 18:15 maildirfolder
drwx------  2 jeff  jeff  5819392 Apr 23 18:42 tmp
drwx------  2 jeff  jeff  5237248 Apr 23 18:42 cur
-rw-------  1 jeff  jeff  4122971 Apr 23 18:42 dovecot-uidlist
-rw-------  1 jeff  jeff       36 Apr 23 18:42 dovecot-keywords
-rw-------  1 jeff  jeff  1650764 Apr 23 18:42 dovecot.index.log.2
-rw-------  1 jeff  jeff  1637008 Apr 23 18:42 dovecot.index
-rw-------  1 jeff  jeff    56124 Apr 23 19:04 dovecot.index.log
-rw-------  1 jeff  jeff  9442304 Apr 23 19:04 dovecot.index.cache
-rw-------  1 jeff  jeff       24 Apr 23 19:04 dovecot-uidlist.lock

(time passes)

It is now 20:35 and it has not advanced. I now no longer believe the 
problem is the mailbox naming, but the indexing.

   PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME   WCPU 
COMMAND
25934 jeff          1 103    0   135M   102M CPU2    2 128:47 100.00% 
doveadm

[jeff at mail ~/Maildir]$ ls -Altr .cron_2010-07-10
total 28
drwx------  2 jeff  jeff      512 Apr 23 18:15 new
-rw-------  1 jeff  jeff        0 Apr 23 18:15 maildirfolder
drwx------  2 jeff  jeff  5819392 Apr 23 18:42 tmp
drwx------  2 jeff  jeff  5237248 Apr 23 18:42 cur
-rw-------  1 jeff  jeff  4122971 Apr 23 18:42 dovecot-uidlist
-rw-------  1 jeff  jeff       36 Apr 23 18:42 dovecot-keywords
-rw-------  1 jeff  jeff  1650764 Apr 23 18:42 dovecot.index.log.2
-rw-------  1 jeff  jeff  1637008 Apr 23 20:26 dovecot.index
-rw-------  1 jeff  jeff   289120 Apr 23 20:36 dovecot.index.log
-rw-------  1 jeff  jeff  9442304 Apr 23 20:36 dovecot.index.cache
-rw-------  1 jeff  jeff       24 Apr 23 20:36 dovecot-uidlist.lock


Any suggestions as to how to proceed?

Jeff