imapd, CPU 100% after viewing a few messages
Robert Scussel
rscuss at omniti.com
Tue Nov 25 09:07:48 EST 2003
It looks like it is haveing some difficulty authenticating...
When I strace I get:
------
select(1, [0], NULL, NULL, {1789, 240000}) = 1 (in [0], left {1782, 750000})
time(NULL) = 1069768897
read(0, "a1 login username password\r\n", 4096) = 22
socket(PF_UNIX, SOCK_STREAM, 0) = 11
connect(11, {sin_family=AF_UNIX, path="
/var/state/saslauthd/mux"},
110) = 0
writev(11, [{"\0\6username\0\004password\0\4imap\0\0", 22}], 1) = 22
read(11, "\0\2", 2) = 2
read(11, "OK", 2) = 2
----
another thing that seems odd in your strace is that it looks like it
tries to connect to a mysql instance, then it tries to check the
/etc/password file, then it reports no database selected.... are you
using an MySQL auxprop?
I know it's probably already been checked, but I show similar problems
when saslauthd isn't running correctly...
HTH
B
warren at netlab.co.za wrote:
> Greetings All
>
> I have managed to strace the 'looped' imap process. I did the following.
> Restarted cyrus and opened a mailbox with squirrel. Started STrace on the pid.
> I then opened mail until the imapd process started using all available cpu
> cycles. This is the strace output:
>
> [root at XServerII root]# cat imap.trace | more
> accept(4, 0, NULL) = 0
> fcntl64(7, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
> alarm(0) = 42
> getpid() = 15239
> getpeername(0, {sin_family=AF_INET, sin_port=htons(37838), sin_addr=inet_addr("1
> 27.0.0.1")}}, [16]) = 0
> getpeername(0, {sin_family=AF_INET, sin_port=htons(37838), sin_addr=inet_addr("1
> 27.0.0.1")}}, [16]) = 0
> getsockname(0, {sin_family=AF_INET, sin_port=htons(143), sin_addr=inet_addr("127
> .0.0.1")}}, [16]) = 0
> open("/etc/hosts.allow", O_RDONLY) = 1
> fstat64(1, {st_mode=S_IFREG|0644, st_size=161, ...}) = 0
> mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40
> 241000
> read(1, "#\n# hosts.allow\tThis file descri"..., 4096) = 161
> read(1, "", 4096) = 0
> close(1) = 0
> munmap(0x40241000, 4096) = 0
> open("/etc/hosts.deny", O_RDONLY) = 1
> fstat64(1, {st_mode=S_IFREG|0644, st_size=347, ...}) = 0
> mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40
> 241000
> read(1, "#\n# hosts.deny\tThis file describ"..., 4096) = 347
> read(1, "", 4096) = 0
> close(1) = 0
> munmap(0x40241000, 4096) = 0
> write(3, "\2\0\0\0", 4) = 4
> time([1069742951]) = 1069742951
> getpid() = 15239
> rt_sigaction(SIGPIPE, {0x420d6aa0, [], SA_RESTORER, 0x42028c48}, {SIG_IGN}, 8) =
> 0
> send(9, "<183>Nov 25 08:49:11 imapd[15239"..., 54, 0) = 54
> rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
> dup2(0, 1) = 1
> dup2(0, 2) = 2
> write(3, "\3\0\0\0", 4) = 4
> getpeername(0, {sin_family=AF_INET, sin_port=htons(37838), sin_addr=inet_addr("1
> 27.0.0.1")}}, [16]) = 0
> socket(PF_UNIX, SOCK_STREAM, 0) = 8
> connect(8, {sin_family=AF_UNIX, path="/var/run/.nscd_socket"}, 110) = -1 ENOENT
> (No such file or directory)
> close(8) = 0
> open("/etc/hosts", O_RDONLY) = 8
> fcntl64(8, F_GETFD) = 0
> fcntl64(8, F_SETFD, FD_CLOEXEC) = 0
> fstat64(8, {st_mode=S_IFREG|0644, st_size=288, ...}) = 0
> mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40
> 241000
> read(8, "# Do not remove the following li"..., 4096) = 288
> close(8) = 0
> munmap(0x40241000, 4096) = 0
> getsockname(0, {sin_family=AF_INET, sin_port=htons(143), sin_addr=inet_addr("127
> .0.0.1")}}, [16]) = 0
> getpid() = 15239
> open("/var/imap/proc/15239", O_RDWR|O_CREAT|O_TRUNC, 0666) = 8
> fstat64(8, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
> mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40
> 241000
> _llseek(8, 0, [0], SEEK_SET) = 0
> write(8, "localhost.localdomain[127.0.0.1]"..., 33) = 33
> _llseek(8, 0, [33], SEEK_CUR) = 0
> ftruncate(8, 33) = 0
> open("/var/imap/msg/motd", O_RDONLY) = -1 ENOENT (No such file or directory)
> select(1, [0], NULL, NULL, {0, 0}) = 0 (Timeout)
> write(1, "* OK XServerII Cyrus IMAP4 v2.1."..., 49) = 49
> time(NULL) = 1069742951
> select(1, [0], NULL, NULL, {1800, 0}) = 1 (in [0], left {1799, 997983})
> time(NULL) = 1069742951
> read(0, "A001 LOGIN \"warren\" \"password\"\r\n", 4096) = 32
> socket(PF_UNIX, SOCK_STREAM, 0) = 10
> fcntl64(10, F_GETFL) = 0x2 (flags O_RDWR)
> connect(10, {sin_family=AF_UNIX, path="/var/lib/mysql/mysql.sock"}, 110) = 0
> setsockopt(10, SOL_IP, IP_TOS, [8], 4) = -1 EOPNOTSUPP (Operation not supported
> )
> setsockopt(10, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
> read(10, "(\0\0\0", 4) = 4
> read(10, "\n3.23.52\0S\25\0\0r*u13Mf=\0, \10\2\0\0\0\0\0\0"..., 40) = 40
> geteuid32() = 503
> ioctl(0, SNDCTL_TMR_TIMEBASE, 0xbfffba90) = -1 EINVAL (Invalid argument)
> geteuid32() = 503
> open("/etc/passwd", O_RDONLY) = 11
> fcntl64(11, F_GETFD) = 0
> fcntl64(11, F_SETFD, FD_CLOEXEC) = 0
> fstat64(11, {st_mode=S_IFREG|0644, st_size=2341, ...}) = 0
> mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40
> 242000
> read(11, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 2341
> close(11) = 0
> munmap(0x40242000, 4096) = 0
> write(10, "\v\0\0\1\205 \0\0\0cyrus\0", 15) = 15
> read(10, "\5\0\0\2", 4) = 4
> read(10, "\0\0\0\2\0", 5) = 5
> fcntl64(10, F_SETFL, O_RDWR|O_NONBLOCK) = 0
> read(10, 0x812e470, 8192) = -1 EAGAIN (Resource temporarily unavai
> lable)
> fcntl64(10, F_SETFL, O_RDWR) = 0
> write(10, "\1\0\0\0\2", 5) = 5
> read(10, "\27\0\0\1", 4) = 4
> read(10, "\377\26\4No Database Selected", 23) = 23
> fcntl64(10, F_SETFL, O_RDWR|O_NONBLOCK) = 0
> read(10, 0x812e470, 8192) = -1 EAGAIN (Resource temporarily unavai
> lable)
> fcntl64(10, F_SETFL, O_RDWR) = 0
> write(10, "\1\0\0\0\1", 5) = 5
> shutdown(10, 2 /* send and receive */) = 0
> close(10) = 0
> socket(PF_UNIX, SOCK_STREAM, 0) = 10
> fcntl64(10, F_GETFL) = 0x2 (flags O_RDWR)
> connect(10, {sin_family=AF_UNIX, path="/var/lib/mysql/mysql.sock"}, 110) = 0
> setsockopt(10, SOL_IP, IP_TOS, [8], 4) = -1 EOPNOTSUPP (Operation not supported
> )
> setsockopt(10, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
> read(10, "(\0\0\0", 4) = 4
> read(10, "\n3.23.52\0T\25\0\0MUC/`uNf\0, \10\2\0\0\0\0\0\0"..., 40) = 40
> geteuid32() = 503
> ioctl(0, SNDCTL_TMR_TIMEBASE, 0xbfffba90) = -1 EINVAL (Invalid argument)
> geteuid32() = 503
> open("/etc/passwd", O_RDONLY) = 11
> fcntl64(11, F_GETFD) = 0
> fcntl64(11, F_SETFD, FD_CLOEXEC) = 0
> fstat64(11, {st_mode=S_IFREG|0644, st_size=2341, ...}) = 0
> mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40
> 242000
> read(11, "root:x:0:0:root:/root:/bin/bash\n"..., 4096) = 2341
> close(11) = 0
> munmap(0x40242000, 4096) = 0
> write(10, "\v\0\0\1\205 \0\0\0cyrus\0", 15) = 15
> read(10, "\5\0\0\2", 4) = 4
> read(10, "\0\0\0\2\0", 5) = 5
> fcntl64(10, F_SETFL, O_RDWR|O_NONBLOCK) = 0
> read(10, 0x812e470, 8192) = -1 EAGAIN (Resource temporarily unavai
> lable)
> fcntl64(10, F_SETFL, O_RDWR) = 0
> write(10, "\1\0\0\0\2", 5) = 5
> read(10, "\27\0\0\1", 4) = 4
> read(10, "\377\26\4No Database Selected", 23) = 23
> fcntl64(10, F_SETFL, O_RDWR|O_NONBLOCK) = 0
> read(10, 0x812e470, 8192) = -1 EAGAIN (Resource temporarily unavai
> lable)
> fcntl64(10, F_SETFL, O_RDWR) = 0
> write(10, "\1\0\0\0\1", 5) = 5
> shutdown(10, 2 /* send and receive */) = 0
> close(10) = 0
> socket(PF_UNIX, SOCK_STREAM, 0) = 10
> connect(10, {sin_family=AF_UNIX, path="/var/run/saslauth/mux"}, 110) = 0
> writev(10, [{"\0\6warren\0\10password\0\4imap\0\0", 26}], 1) = 26
> read(10, "", 2) = 0
> read(10, "", 2) = 0
> read(10, "", 2) = 0
> read(10, "", 2) = 0
> read(10, "", 2) = 0
> read(10, "", 2) = 0
> read(10, "", 2) = 0
> read(10, "", 2) = 0
>
> At this point the last line repeats indefinitely. The only output from the
> trace that has been editored is the password, changed to 'password'. Any Ideas
> of what the problem is?
>
> Regards
> Warren
>
> Quoting warren at netlab.co.za:
>
>
>>Greetings
>>
>>I have been setting up a new cyrus-postfix-amavis(new)-spamassassin system
>>and
>>have come across a problem. Cyrus master starts without problems. I can send
>>
>>messages and I can usually view the message. But for some reason, after
>>viewing
>>a few messages the imapd process starts using 100% of CPU.
>>
>>Unfortunately there is very little other info that I can send. The imapd.log
>>
>>shows nothing unusual. The only entry that resembles a problem is
>>
>>Nov 24 15:09:13 xserverii imapd[10410]: SQUAT failed to open index file
>>Nov 24 15:09:13 xserverii imapd[10410]: SQUAT failed
>>
>>but after a google or two it seems that this is normal.
>>
>>Messages logs shows nothing unusual. Neither does maillog or auth.log.
>>
>>I can always reproduce the problem by using squirrel mail (outlook also shows
>>
>>shows the same problem so it is not a client problem) by going though the
>>first
>>6 emails. Before the end of the list the problem presents itself (sometimes
>>on
>>message one, but usually I can view a few before the problem starts).
>>
>>All software (cyrus/postfix) are the latest stables as of a few weeks ago.
>>The
>>system is RH8.0.
>>
>>I have tried to use gdb in an attempt to offer something more in this request
>>
>>but have been unable to obtain any useful info (this is the first time I have
>>
>>attempted used gdb seriously, so its mostly my ignorance that is the
>>problem).
>>
>>Any ideas of how to track this problem down would be most welcome.
>>
>>Regards
>>Warren
>>
>>
>>
>
>
>
--
Robert Scussel
1024D/BAF70959/0036 B19E 86CE 181D 0912 5FCC 92D8 1EA1 BAF7 0959
More information about the Info-cyrus
mailing list