[Dovecot] Huge IMAP folder takes forever

[Peter Lindgren]

Update: I did a kernel trace to see what the imap process was doing, and
it was retrieving headers, but to me it seemed like there were an awful
lot of null (\0) and control characters among the headers. Excerpts of
the trace below, actual mail address hidden to protect the innocent.

It's difficult to trace a folder that works, since that imap process
doesn't live long enough for me to trace it. Hints on that, other than
being really quick on the keyboard? ;-) The traces I've managed has nice
plaintext commands like these:
   2994 imap     1165779379.972538 GIO   fd 1 wrote 23 bytes
        "24 OK NOOP completed.\r
        "
   2994 imap     1165779379.972620 RET   write 23/0x17
...
   2994 imap     1165779379.977092 CALL  read(0,0x6be31b,0xce5)
   2994 imap     1165779379.977179 GIO   fd 0 read 29 bytes
        "25 UID fetch 3657:* (FLAGS)\r
        "
   2994 imap     1165779379.977245 RET   read 29/0x1d


However, these reads/writes are to other file descriptors (0 and 1) than
the erraneous reads below (fd 8).


My system:
# uname -ap
OpenBSD casiopea.norrskenkonsult.com 3.7 GENERIC#312 sparc
SUNW,SPARCstation-5, MB86907 @ 170 MHz, on-chip FPU



# kdump -T -f imap.tracelog
   9506 imap     1165775763.392950 EMUL  "native"
   9506 imap     1165775763.521181 CALL  munmap(0xbef8000,0x100000)
   9506 imap     1165775763.526077 RET   munmap 0
   9506 imap     1165775763.563349 CALL  munmap(0xbeb7000,0x41000)
   9506 imap     1165775763.564797 RET   munmap 0
   9506 imap     1165775763.564899 CALL  munmap(0xbeb6000,0x1000)
   9506 imap     1165775763.565074 RET   munmap 0
   9506 imap     1165775763.565192 CALL
pread(0x8,0x8580000,0x1000,0,0,0x141000)
   9506 imap     1165775763.566267 GIO   fd 8 read 4088 bytes
        "\0\0\0\^\\0\0\0\0In-Reply-To:
<1137747953.43d0a7f16017b at webbmail.thornqvist.se>
         \0\0\0\0\^N\0\0\0Q\0\0\0\^W\0\0\0\0Message-ID:
<6996e6f30601200332y1f7dcb9fi1397e97e41b9c04 at mail.gmail.com>
         \0\0\0\0\0\0\^Q\0\0\0t\0\0\0 \0\0\0\0References:
<WinLMSG.43cfec50.1783.5ecb at smtp.chello.se.>
                 <1137747953.43d0a7f16017b at webbmail.thornqvist.se>
         \0\0\0\^R\0\0\0*\0\0\0\^[\0\0\0\0Subject: Re: [exakt] Pod-TV i SVT
         \0\0\0\0\0\^S\0\0\0.\0\0\0\^Z\0\0\0\0To: Exakt IT
<exakt at lists.frobbit.se>
         \0\0\0\0\0      \0\0\0\0\0\0\0

\0\0\0\0\0\0\0\v\0\0\0\0\0\0\0\f\0\0\0\0\0\0\0\r\0\0\0\0\0\0\0\^N\0\0\0\0\0\0\0\^O\0\0\0\0\0\0\0\^P\0\0\0\0\0\0\0\^Q\0\0\0\0\0\0\0\^R\0\0\0\0\0\0\0\

\^S\0\0\0\0\0\0\0\^T\0\0\0\0\0\0\0\0\0\0\0\b\0\0\0\b\0\0\0(\0\0\0H\0\0\0\0\0\0
         \M-D\0\0\0\0\0\0

\M-w\0\0\0\0\0\0\^DG\0\0\0\0\0\0\^Dd\0\0\0\^]\0\^A3\M-X\0\0\^B\M-@\0\0\0
         \0\0\0\\\0\0\0\^[\0\0\0\0Content-Type: text/plain;
format=flowed; charset="iso-8859-1";
                 reply-type=response
         \0\0\0\v\0\0\0.\0\0\0\^Y\0\0\0\0Date: Fri, 20 Jan 2006 12:34:59
+0100
         \0\0\0\0\0\f\0\0\0003\0\0\0\^T\0\0\0\0From: "Lars Ilshammar"
<xxxx at xxxxxxxxx.se>
         \0\0\0\0\^N\0\0\0;\0\0\0\^S\0\0\0\0Message-ID:
<004301c61db5$8b847e40$6400a8c0 at LASSE>
         \0\0\0\0\^Q\0\0\0o\0\0\0\^V\0\0\0\0References:
<82ab3b60601192318q7c5d7cf1u6ee17edc0e11da92 at mail.gmail.com>
                 <43D09D62.2080005 at abm.uu.se>
         \0\0\0\0\^R\0\0\0)\0\0\0\^X\0\0\0\0Subject: Re: [exakt] SMHI suger!
         \0\0\0\0\0\0\^S\0\0\0000\0\0\0\^U\0\0\0\0To: "Exakt IT"
<exakt at lists.frobbit.se>
         \0\0\0\^T\0\0\0\^V\0\0\0\^^\0\0\0\0X-Priority: 3
         \0\0\0\0\0      \0\0\0\0\0\0\0

\0\0\0\0\0\0\0\v\0\0\0\0\0\0\0\f\0\0\0\0\0\0\0\r\0\0\0\0\0\0\0\^N\0\0\0\0\0\0\0\^O\0\0\0\0\0\0\0\^P\0\0\0\0\0\0\0\^Q\0\0\0\0\0\0\0\^R\0\0\0\0\0\0\0\

\^S\0\0\0\0\0\0\0\^T\0\0\0\0\0\0\0\0\0\0\0\b\0\0\0\b\0\0\0(\0\0\0H\0\0\0\0\0\0\b\M-<\0\0\0\0\0\0\b\M-l\0\0\0\0\0\0\^O\M-~\0\0\0\0\0\0\^PZ\0\0\0\\\0\
         \^A3\M-l\0\0\^B\M-T\0\0\0
         \0\0\0F\0\0\0\^X\0\0\0\0Content-Type: text/plain;
format=flowed; charset="iso-8859-1"
         \0\0\0\0\0\v\0\0\0.\0\0\0\^V\0\0\0\0Date: Fri, 20 Jan 2006
13:06:34 +0100

... continues like that until ...

   9506 imap     1165775763.566267 GIO   fd 8 read 8 bytes
        "\0\0\0\f\0\0\0H"
   9506 imap     1165775763.566912 RET   pread 4096/0x1000
   9506 imap     1165775763.570811 CALL
mmap(0,0x144000,0x3,0x1002,0xffffffff,0,0,0)
   9506 imap     1165775763.570972 RET   mmap 256024576/0xf42a000
   9506 imap     1165775763.715347 CALL  munmap(0x8481000,0x100000)
   9506 imap     1165775763.719472 RET   munmap 0
   9506 imap     1165775763.757083 CALL  munmap(0x843f000,0x42000)
   9506 imap     1165775763.758449 RET   munmap 0
   9506 imap     1165775763.758569 CALL  munmap(0x843e000,0x1000)
   9506 imap     1165775763.758735 RET   munmap 0
   9506 imap     1165775763.758854 CALL
pread(0x8,0xf56d000,0x1000,0,0,0x142000)
   9506 imap     1165775763.759294 GIO   fd 8 read 4088 bytes

...

/Peter
-- 
Peter Lindgren, dataingenjör
E-post: peter "at" norrskenkonsult punkt com
http://www.norrskenkonsult.com