imapd, CPU 100% after viewing a few messages

warren at netlab.co.za warren at netlab.co.za
Tue Nov 25 01:57:40 EST 2003


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
> 
> 
> 






More information about the Info-cyrus mailing list