- Timo Sirainen tss@iki.fi:
My idea is to turn back on logging and then trace the dovecot/log process using
strace -p PID -c
-tt is also nice.
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) = 0two consecutive getdents64 calls on the same FD, one fast, one slow. WTF?
# ll /usr/dovecot-2/lib/dovecot/settings total 88 -rw-r--r-- 1 root root 24766 Okt 21 21:27 libmanagesieve_login_settings.a -rwxr-xr-x 1 root root 1107 Okt 21 21:27 libmanagesieve_login_settings.la -rwxr-xr-x 1 root root 23291 Okt 21 21:27 libmanagesieve_login_settings.so -rw-r--r-- 1 root root 11630 Okt 21 21:27 libmanagesieve_settings.a -rwxr-xr-x 1 root root 1065 Okt 21 21:27 libmanagesieve_settings.la -rwxr-xr-x 1 root root 12858 Okt 21 21:27 libmanagesieve_settings.so
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) = 0on fast call, one slow call.
Sorting all traces by execution time:
% cat dovecot-lda.* | sort -n -k1 |less 0.094459 fstat64(8, {st_mode=S_IFREG|0755, st_size=1870288, ...}) = 0 0.095051 brk(0x8d73000) = 0x8d73000 0.098191 getdents64(8, /* 0 entries */, 32768) = 0 0.098912 time(NULL) = 1288084930 0.103059 getdents64(8, /* 0 entries */, 32768) = 0 0.110251 getdents64(8, /* 0 entries */, 32768) = 0 0.115710 getdents64(8, /* 0 entries */, 32768) = 0 0.117688 time(NULL) = 1288084937 0.128360 getdents64(8, /* 0 entries */, 32768) = 0 0.130091 mprotect(0xb75b4000, 4096, PROT_READ) = 0 0.131681 rt_sigaction(SIGALRM, {0xb76cb490, [], SA_SIGINFO}, NULL, 8) = 0 0.133327 getdents64(8, /* 0 entries */, 32768) = 0 0.134047 stat64("/home/c/o/cousername/Maildir/dovecot-uidlist", {st_mode=S_IFREG|0600, st_size=1130, ...}) = 0 0.135077 rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTART}, NULL, 8) = 0 0.150525 getdents64(8, /* 0 entries */, 32768) = 0 0.153457 open("/home/f/k/fkusername/Maildir/dovecot-uidlist", O_RDWR|O_LARGEFILE) = 11 0.170190 getdents64(8, /* 0 entries */, 32768) = 0 0.188536 getdents64(8, /* 0 entries */, 32768) = 0 0.193665 umask(077) = 0177 0.270003 getdents64(8, /* 0 entries */, 32768) = 0
Ralf Hildebrandt Geschäftsbereich IT | Abteilung Netzwerk Charité - Universitätsmedizin Berlin Campus Benjamin Franklin Hindenburgdamm 30 | D-12203 Berlin Tel. +49 30 450 570 155 | Fax: +49 30 450 570 962 ralf.hildebrandt@charite.de | http://www.charite.de