Brian Candler schrieb:
On Wed, Apr 12, 2006 at 06:14:53PM +0200, Bernd Schindler wrote:
I have a strange problem with my courier IMAP 3.0.8 on Debian
"etch". When I try to examine/select INBOX (or any other subfolder)
it takes several (up to 15) minutes for the command to complete. I
tested it on an newly created Maildir which was completely emty and
the problem was the same. POP3 works fine so I think, that my
maildirs are OK. I also tried IMAP 4.1.0 from Debian "experimental"
and it also was the same problem.
Can anybody help me with my problem or even tell me how I can debug
my imapd?
- locate the imapd process serving your connection (using ps, netstat
etc)
- attach a strace to it:
# strace -f -p <pid>
- see what system calls it is making
- post that information here
If you can replicate this problem using telnet to port 143, and manually
issuing the examine/select, then it will be easier to debug: you can
attach
the strace process after logging in but before issuing the
examine/select,
so you'll see the whole set of operations.
I suspect that either it's hanging on some I/O operation, or else it's
livelocking for some reason (doing the same thing over and over
again), but
without the strace information I can't think why it would be doing so.
When you say "POP3 works fine" is that using courier's pop3d, or
something
else (e.g. qmail pop3d)?
HTH,
Brian.
It seems, that imapd wants to establish some kind of tcp connection
which times out, but I don't know exactly what these lines mean.
I first started imapd manually with "/usr/bin/imapd Maildir" and started
strace. After I entered "a1 examine INBOX" it produced the following
output: (I marked the parts where it hung)
select(1, [0], NULL, NULL, {1787, 97000}) = 1 (in [0], left {1776,
234000})
read(0, "a1 examine INBOX\n", 8192) = 17
access("./.", F_OK) = 0
open("././courierimapacl", O_RDONLY) = -1 ENOENT (No such file or
directory)
getcwd("/root/Maildir", 4095) = 14
open("/etc/nsswitch.conf", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=465, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7fad000
read(3, "# /etc/nsswitch.conf\n#\n# Example"..., 4096) = 465
read(3, "", 4096) = 0
close(3) = 0
munmap(0xb7fad000, 4096) = 0
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=21025, ...}) = 0
old_mmap(NULL, 21025, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7fa8000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
open("/usr/lib/libnss_db.so.2", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\0\21\0"...,
512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=16540, ...}) = 0
old_mmap(NULL, 19820, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3,
0) = 0xb7ce4000
old_mmap(0xb7ce8000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0xb7ce8000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
open("/lib/tls/libnss_files.so.2", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\220\33"...,
512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=42472, ...}) = 0
old_mmap(NULL, 45720, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3,
0) = 0xb7cd8000
old_mmap(0xb7ce2000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x9000) = 0xb7ce2000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or
directory)
open("/usr/lib/libdb-4.3.so", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\220o\1"...,
512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=935540, ...}) = 0
old_mmap(NULL, 935004, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE,
3, 0) = 0xb7bf3000
old_mmap(0xb7cd5000, 12288, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xe2000) = 0xb7cd5000
close(3) = 0
munmap(0xb7fa8000, 21025) = 0
open("/etc/mtab", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=203, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7fad000
read(3, "/dev/md1 / ext3 rw 0 0\nproc /pro"..., 4096) = 203
close(3) = 0
munmap(0xb7fad000, 4096) = 0
open("/proc/stat", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7fad000
read(3, "cpu 8970 942 1236 9937734 6409 "..., 1024) = 666
read(3, "", 1024) = 0
close(3) = 0
munmap(0xb7fad000, 4096) = 0
open("/var/lib/misc/rpc.db", O_RDWR|O_LARGEFILE) = -1 ENOENT (No such
file or directory)
open("/var/lib/misc/rpc.db", O_RDWR|O_LARGEFILE) = -1 ENOENT (No such
file or directory)
open("/var/lib/misc/rpc.db", O_RDWR|O_LARGEFILE) = -1 ENOENT (No such
file or directory)
stat64("/var/lib/misc/rpc.db", 0xbfcbd37c) = -1 ENOENT (No such file or
directory)
open("/etc/rpc", O_RDONLY) = 3
fcntl64(3, F_GETFD) = 0
fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
fstat64(3, {st_mode=S_IFREG|0644, st_size=887, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb7fad000
read(3, "# This file contains user readab"..., 4096) = 887
close(3) = 0
munmap(0xb7fad000, 4096) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
bind(3, {sa_family=AF_INET, sin_port=htons(0),
sin_addr=inet_addr("0.0.0.0")}, 16) = 0
connect(3, {sa_family=AF_INET, sin_port=htons(111),
sin_addr=inet_addr("127.0.0.1")}, 16
############### 5 MINUTES WAITING ###############
) = -1 ETIMEDOUT (Connection timed out)
close(3) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
getpid() = 7391
bind(3, {sa_family=AF_INET, sin_port=htons(783),
sin_addr=inet_addr("0.0.0.0")}, 16) = 0
connect(3, {sa_family=AF_INET, sin_port=htons(111),
sin_addr=inet_addr("127.0.0.1")}, 16
############### 5 MINUTES WAITING ###############
) = -1 ETIMEDOUT (Connection timed out)
close(3) = 0
gettimeofday({1144945504, 850877}, NULL) = 0
stat64("./tmp/1144945504.M850877P7391_courierlock.alpha894.server4you.de",
0xbfcbe65c) = -1 ENOENT (No such file or directory)
open("./tmp/1144945504.M850877P7391_courierlock.alpha894.server4you.de",
O_RDWR|O_NONBLOCK|O_CREAT|O_TRUNC, 0644) = 3
fcntl64(3, F_SETFL, O_RDONLY) = 0
fstat64(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
lstat64("./tmp/1144945504.M850877P7391_courierlock.alpha894.server4you.de",
{st_mode=S_IFREG|0644, st_size=0, ...}) = 0
close(3) = 0
uname({sys="Linux", node="alpha894.server4you.de", ...}) = 0
open("./tmp/1144945504.M850877P7391_courierlock.alpha894.server4you.de",
O_RDWR|O_CREAT, 0644) = 3
write(3, "7391:alpha894.server4you.de", 27) = 27
close(3) = 0
link("./tmp/1144945504.M850877P7391_courierlock.alpha894.server4you.de",
"./tmp/courier.lock") = 0
stat64("./tmp/1144945504.M850877P7391_courierlock.alpha894.server4you.de",
{st_mode=S_IFREG|0644, st_size=27, ...}) = 0
unlink("./tmp/1144945504.M850877P7391_courierlock.alpha894.server4you.de")
= 0
time([1144945504]) = 1144945504
open("./tmp", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 3
fstat64(3, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
getdents64(3, /* 3 entries */, 4096) = 80
stat64("./tmp/courier.lock", {st_mode=S_IFREG|0644, st_size=27, ...}) = 0
getdents64(3, /* 0 entries */, 4096) = 0
close(3) = 0
gettimeofday({1144945504, 852701}, NULL) = 0
stat64("./tmp/1144945504.M852701P7391_imapuid_0.alpha894.server4you.de",
0xbfcbdc1c) = -1 ENOENT (No such file or directory)
open("./tmp/1144945504.M852701P7391_imapuid_0.alpha894.server4you.de",
O_RDWR|O_NONBLOCK|O_CREAT|O_TRUNC, 0644) = 3
fcntl64(3, F_SETFL, O_RDONLY) = 0
fstat64(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
lstat64("./tmp/1144945504.M852701P7391_imapuid_0.alpha894.server4you.de",
{st_mode=S_IFREG|0644, st_size=0, ...}) = 0
close(3) = 0
open("./courierimapuiddb", O_RDONLY) = -1 ENOENT (No such file or
directory)
time(NULL) = 1144945504
open("./tmp/1144945504.M852701P7391_imapuid_0.alpha894.server4you.de",
O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
open("./cur", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 4
fstat64(4, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
getdents64(4, /* 2 entries */, 4096) = 48
getdents64(4, /* 0 entries */, 4096) = 0
close(4) = 0
open("./new", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY) = 4
fstat64(4, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
fcntl64(4, F_SETFD, FD_CLOEXEC) = 0
getdents64(4, /* 2 entries */, 4096) = 48
getdents64(4, /* 0 entries */, 4096) = 0
close(4) = 0
close(3) = 0
unlink("./tmp/1144945504.M852701P7391_imapuid_0.alpha894.server4you.de")
= 0
time(NULL) = 1144945504
open("./courierimapkeywords/:list", O_RDONLY) = -1 ENOENT (No such file
or directory)
mkdir("./courierimapkeywords", 0700) = -1 EEXIST (File exists)
stat64(".", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
chmod("./courierimapkeywords", 0700) = 0
unlink("./tmp/courier.lock") = 0
time([1144945504]) = 1144945504
select(2, NULL, [1], NULL, {60, 0}) = 1 (out [1], left {60, 0})
write(1, "* FLAGS (\\Draft \\Answered \\Flagg"..., 227) = 227
time([1144945504]) = 1144945504
time([1144945504]) = 1144945504
select(1, [0], NULL, NULL, {1800, 0}
