On Sun, Nov 04, 2007 at 11:28:36AM -0500, Adam McDougall wrote:
I noticed some sluggish message body fetches today that I don't think I've seen before. Each time I fetch a message from this particular mailbox (network/2007/01-Jan for my own record) it takes a few seconds, and mutt makes it look like the fetch was "slow". So did thunderbird. I didn't waste any time and tried to grab a truss and kdump of the action asap (attached). Apparently strace is only available on i386 for FreeBSD, but truss and kdump should be similar, depends what details you are looking for.
It looks like the message fetch actually reads in from disk fairly promptly (you can see the whole spam message in the kdump output) but then it churns away for a while with something like the below:
fstat(13,{mode=-rw------- ,inode=5656735,size=817368,blksize=4096}) = 0 (0x0) fchown(0xd,0x5321,0xffffffff) = 0 (0x0) madvise(0x10649000,0x82000,0x4) = 0 (0x0) fstat(13,{mode=-rw------- ,inode=5656735,size=817368,blksize=4096}) = 0 (0x0) fchown(0xd,0x5321,0xffffffff) = 0 (0x0) madvise(0x10649000,0x82000,0x4) = 0 (0x0) fstat(13,{mode=-rw------- ,inode=5656735,size=817368,blksize=4096}) = 0 (0x0) fchown(0xd,0x5321,0xffffffff) = 0 (0x0) madvise(0x10649000,0x82000,0x4) = 0 (0x0) fstat(13,{mode=-rw------- ,inode=5656735,size=817368,blksize=4096}) = 0 (0x0) fchown(0xd,0x5321,0xffffffff) = 0 (0x0) madvise(0x10649000,0x82000,0x4) = 0 (0x0) fstat(13,{mode=-rw------- ,inode=5656735,size=817368,blksize=4096}) = 0 (0x0) fchown(0xd,0x5321,0xffffffff) = 0 (0x0) madvise(0x10649000,0x82000,0x4) = 0 (0x0) fstat(13,{mode=-rw------- ,inode=5656735,size=817368,blksize=4096}) = 0 (0x0) fchown(0xd,0x5321,0xffffffff) = 0 (0x0) madvise(0x10649000,0x82000,0x4) = 0 (0x0)
For now I plan to leave mutt with the current folder selected, incase something I do makes the behavior go away.
Oops, forgot to mention this was with dovecot 1.1b6, no local patches.