[Dovecot] FreeBSD 6.1-RELEASE/kqueue high CPU load
Taras Savchuk
taras at elantech.ru
Tue Sep 19 02:21:06 EEST 2006
LI Xin пишет:
> Taras Savchuk wrote:
>
>> LI Xin пишет:
>>
>>> Paul Lathrop wrote:
>>>
>>>
>>>> Taras Savchuk wrote:
>>>>
>>>>
>>>>> Hi to ALL!
>>>>>
>>>>> I have dovecot-1.0r7 installed on FreeBSD 6.1, using kqueue and
>>>>> Maildir (<20 mailboxes, < 0,5 Gb size). Periodically CPU load of imap
>>>>> processes increasing up to 60-80%.
>>>>> Is it normall behavior or not? May be somebody had such kind of
>>>>> problems?
>>>>>
>>>>>
>>>>>
>>>> I have also experienced this behavior, which is quite bothersome because
>>>> I sold my supervisor on Dovecot by talking about performance and low
>>>> resource requirements...
>>>>
>>>>
>>> What if you get some output from ktrace/kdump? Additionally, try to
>>> force the process to save a coredump and investigate its .core with gdb
>>> would help tracking down the issue...
>>>
>>> Note that because when using kqueue the process should get a "kqread" if
>>> it is waiting for kqueue event. If the process is stuck in "RUN" state
>>> then a coredump would be more helpful.
>>>
>>> Cheers,
>>>
>>>
>> I cought imap while eating much CPU (~80%) and run ktrace -t + -p <bad
>> process pid>.
>> It's kdump -E output, many gettimeofday() calls, is it normal? :
>>
>> mail2# kdump -E -f ktrace.out | less
>> 26208 imap 0.000000 RET kevent 0
>> 26208 imap 0.000042 CALL gettimeofday(0x80c2c60,0x80c2c68)
>> 26208 imap 0.000046 RET gettimeofday 0
>> 26208 imap 0.000061 CALL gettimeofday(0xbfbfe9a0,0)
>> 26208 imap 0.000064 RET gettimeofday 0
>> 26208 imap 0.000078 CALL kevent(0x4,0,0,0x80d1000,0x5,0xbfbfe998)
>> 26208 imap 0.000082 RET kevent 0
>> 26208 imap 0.000100 CALL gettimeofday(0x80c2c60,0x80c2c68)
>> 26208 imap 0.000103 RET gettimeofday 0
>> 26208 imap 0.000116 CALL gettimeofday(0xbfbfe9a0,0)
>> 26208 imap 0.000119 RET gettimeofday 0
>> 26208 imap 0.000131 CALL kevent(0x4,0,0,0x80d1000,0x5,0xbfbfe998)
>> 26208 imap 0.474998 RET kevent 0
>>
> [snip]
>
> This looks quite normal... I am not really sure about what is
> happening. Is the CPU consumed by in-kernel operation? (systat -vm or
> top's output would be helpful)
>
> Cheers,
>
Here are top's ans systat -vm 's output:
mail2# top
last pid: 68406; load averages: 1.09, 0.55,
0.38 up 1+09:40:06
03:18:34
139 processes: 2 running, 137 sleeping
CPU states: 7.1% user, 0.0% nice, 43.0% system, 0.0% interrupt, 49.9%
idle
Mem: 942M Active, 777M Inact, 175M Wired, 85M Cache, 112M Buf, 24M Free
Swap: 2022M Total, 2022M Free
PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND
61291 email 1 114 0 3528K 2120K RUN 0 3:09 85.50% imap
62547 email 1 4 0 6168K 2644K kqread 0 0:32 3.81% imap
60522 email 1 4 0 3416K 1860K kqread 0 0:23 0.24% imap
2083 10005 1 4 0 198M 95412K accept 0 27:40 0.00% httpd
2085 10005 1 4 0 198M 93952K accept 0 16:09 0.00% httpd
2084 10005 1 4 0 198M 94912K accept 0 16:01 0.00% httpd
2231 mysql 1 4 14 524M 409M sbwait 0 9:37 0.00% mysqld
1569 10003 1 4 0 153M 31936K accept 0 7:47 0.00% httpd
1570 10003 1 4 0 159M 38560K accept 0 7:46 0.00% httpd
1573 mysql 1 4 14 524M 409M sbwait 0 6:09 0.00% mysqld
2232 mysql 1 4 14 524M 409M sbwait 0 6:08 0.00% mysqld
2229 mysql 1 4 14 524M 409M sbwait 0 3:13 0.00% mysqld
1565 mysql 1 4 14 524M 409M sbwait 0 3:11 0.00% mysqld
1213 10001 1 4 0 171M 61252K accept 0 1:54 0.00% httpd
1212 10001 1 4 0 153M 43660K accept 0 1:51 0.00% httpd
1211 10001 1 4 0 153M 42052K accept 0 1:51 0.00% httpd
1010 elantech 1 20 0 155M 77364K lockf 0 1:38 0.00% httpd
1009 elantech 1 4 0 168M 93660K kqread 0 1:37 0.00% httpd
1011 elantech 1 20 0 161M 86424K lockf 0 1:33 0.00% httpd
2234 mysql 1 4 14 524M 409M sbwait 0 1:01 0.00% mysqld
2184 mysql 1 4 14 524M 409M sbwait 0 0:57 0.00% mysqld
2227 mysql 1 4 14 524M 409M sbwait 0 0:56 0.00% mysqld
1366 10002 1 20 0 161M 48900K lockf 0 0:39 0.00% httpd
1367 10002 1 4 0 153M 41364K kqread 0 0:38 0.00% httpd
662 mysql 1 20 14 524M 409M pause 0 0:13 0.00% mysqld
658 mysql 1 110 14 524M 409M select 0 0:09 0.00% mysqld
2230 mysql 1 4 14 524M 409M sbwait 0 0:09 0.00% mysqld
2233 mysql 1 4 14 524M 409M sbwait 0 0:08 0.00% mysqld
657 mysql 1 110 14 524M 409M select 0 0:08 0.00% mysqld
611 mysql 1 20 14 524M 409M pause 0 0:06 0.00% mysqld
405 bind 1 4 0 5672K 4420K select 0 0:04 0.00% named
613 root 1 4 0 1396K 964K kqread 0 0:03 0.00% dovecot
65753 root 1 96 0 2632K 1680K CPU0 0 0:03 0.00% top
632 root 1 4 0 2412K 1624K kqread 0 0:02 0.00%
dovecot-auth
610 mysql 1 20 14 524M 409M pause 0 0:02 0.00% mysqld
mail2# systat -vm
2 users Load 1.08 0.56 0.39 19 сен 03:18
Mem:KB REAL VIRTUAL VN PAGER SWAP PAGER
Tot Share Tot Share Free in out in out
Act 967396 18100 1858368 36796 111372 count
All 2021620 26420 83531252 51592 pages
Interrupts
Proc:r p d s w Csw Trp Sys Int Sof Flt cow 4078 total
2 136 266 177 4433 89 133 179244 wire
16: bge
964268 act
20: ata
50.0%Sys 0.0%Intr 0.0%User 0.0%Nice 50.0%Idl 795616 inact 2039
cpu0: time
| | | | | | | | | | 86660 cache 2039
cpu1: time
========================= 24712 free
daefr
Namei Name-cache Dir-cache prcfr
Calls hits % hits % react
4 4 100 pdwake
133 zfod pdpgs
Disks ad4 ozfod intrn
KB/t 0.00 %slo-z 114464 buf
tps 0 tfree 97 dirtybuf
MB/s 0.00 100000 desiredvnodes
% busy 0 87066 numvnodes
24995 freevnodes
--
С уважением, Савчук Тарас
ООО "Элантек" : Аутсорсинг ИТ, WEB-разработка
+7 (495) 589 68 81
+7 (926) 575 22 11
http://www.elantech.ru
info at elantech.ru
More information about the dovecot
mailing list