Re: [Dovecot] Config review (2.0.5)

On Tue, 2010-10-26 at 11:44 +0200, Ralf Hildebrandt wrote:

I traced around a bit today, in dovecot-lda. A pattern I'm seeing quite often is this:

 0.000853 open("/usr/dovecot-2/lib/dovecot/settings", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 7
 0.000463 fcntl64(7, F_GETFD)       = 0x1 (flags FD_CLOEXEC)
 0.000555 getdents64(7, /* 8 entries */, 32768) = 360
 0.023219 getdents64(7, /* 0 entries */, 32768) = 0
 0.001545 close(7)                  = 0

two consecutive getdents64 calls on the same FD, one fast, one slow. WTF?

I don't know.. Is that directory on local filesystem? Are your mails on the same disk?

And this is happening once more in the same trace:

 0.002036 open("/usr/dovecot-2/lib/dovecot", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 8
 0.000468 fcntl64(8, F_GETFD)       = 0x1 (flags FD_CLOEXEC)
 0.003281 getdents64(8, /* 85 entries */, 32768) = 3736
 0.150525 getdents64(8, /* 0 entries */, 32768) = 0
 0.000490 close(8)                  = 0

on fast call, one slow call.

v1.x was also doing this. It's for loading plugins.

 0.098912 time(NULL)                = 1288084930

time(NULL) should always be a really fast operation. On my somewhat old machine it takes 0.000016 seconds. So if it's taking this long, it seems that the system in general is under heavy load and the individual system call times don't really tell anything.

 0.193665 umask(077)                = 0177

This should be about 0.000016 seconds too.