POP3 stops accepting connections?
Scott Bye
sbye at unifiedgroup.co.uk
Thu Apr 21 22:05:09 EDT 2005
An update - just done an strace, and it seems to be stalling sometimes when trying to read from /dev/random. I'm guessing that because /dev/random is fed from user input, when there is no user input - being a server - entropy runs low and the kernel blocks access.
Sure enough, catting /dev/random reveals only the most pathetic amount of data. I've removed /dev/random and symlinked /dev/urandom instead. Is this likely to cause me any problems?
strace:
accept(4, 0, NULL) = 8
fcntl64(7, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
alarm(0) = 0
getpid() = 22933
getpeername(8, {sa_family=AF_INET, sin_port=htons(38337), sin_addr=inet_addr("xxx.xxx.xxx.xxx")}, [16]) = 0
getpeername(8, {sa_family=AF_INET, sin_port=htons(38337), sin_addr=inet_addr("xxx.xxx.xxx.xxx")}, [16]) = 0
getsockname(8, {sa_family=AF_INET, sin_port=htons(110), sin_addr=inet_addr("xxx.xxx.xxx.xxx")}, [16]) = 0
open("/etc/hosts.allow", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/hosts.deny", O_RDONLY) = -1 ENOENT (No such file or directory)
getpid() = 22933
write(3, "\2\0\0\0\225Y\0\0", 8) = 8
time([1114134946]) = 1114134946
getpid() = 22933
rt_sigaction(SIGPIPE, {0xb7da1500, [], 0}, {SIG_IGN}, 8) = 0
send(5, "<183>Apr 22 02:55:46 pop3[22933]"..., 53, 0) = 53
rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
dup2(8, 0) = 0
dup2(8, 1) = 1
dup2(8, 2) = 2
close(8) = 0
getpid() = 22933
write(3, "\3\0\0\0\225Y\0\0", 8) = 8
getpeername(0, {sa_family=AF_INET, sin_port=htons(38337), sin_addr=inet_addr("xxx.xxx.xxx.xxx")}, [16]) = 0
socket(PF_FILE, SOCK_STREAM, 0) = 8
connect(8, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = 0
writev(8, [{"\2\0\0\0\6\0\0\0\4\0\0\0", 12}, {"Q\262\357\22", 4}], 2) = 16
read(8, "\2\0\0\0\1\0\0\0\34\0\0\0\0\0\0\0\2\0\0\0\4\0\0\0\1\0\0"..., 32) = 32
readv(8, [{"81-178-239-18.dsl.pipex.com\0", 28}, {"", 0}, {"Q\262\357\22", 4}], 3) = 32
read(8, NULL, 0) = 0
close(8) = 0
getsockname(0, {sa_family=AF_INET, sin_port=htons(110), sin_addr=inet_addr("xxx.xxx.xxx.xxx")}, [16]) = 0
getpid() = 22933
open("/var/imap/proc/22933", O_RDWR|O_CREAT|O_TRUNC, 0666) = 8
fstat64(8, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
old_mmap(NULL, 131072, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6913000
_llseek(8, 0, [0], SEEK_SET) = 0
write(8, "81-178-239-18.dsl.pipex.com [81."..., 44) = 44
_llseek(8, 0, [44], SEEK_CUR) = 0
ftruncate(8, 44) = 0
open("/dev/random", O_RDONLY) = 9
read(9,
*** PAUSED HERE ***
"B\202\350\223O\0", 6) = 6
close(9) = 0
gettimeofday({1114134962, 964910}, NULL) = 0
times({tms_utime=1, tms_stime=0, tms_cutime=0, tms_cstime=0}) = 434232887
time([1114134962]) = 1114134962
open("/var/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
select(1, [0], NULL, NULL, {0, 0}) = 0 (Timeout)
write(1, "+OK delilah Cyrus POP3 v2.2.12-G"..., 84) = 84
time(NULL) = 1114134962
select(1, [0], NULL, NULL, {600, 0}
Regards,
Scott
----- Original Message -----
From: Scott Bye
To: info-cyrus at lists.andrew.cmu.edu
Sent: Friday, April 22, 2005 2:51 AM
Subject: POP3 stops accepting connections?
Hi,
I've just installed Cyrus 2.2.12 as a mailbox solution, but an having a small problem with POP3 - it seems to stop processing connections. For example - I've just done a whole load of consecutive send and recieves, which flew through. Then all of a sudden it stops, and connections can take anything up to a fair few minutes to get the POP3 banner. It's not a big deal at the moment, but I have no doubt users will start complaining soon!
I've tried the same thing with IMAP and don't seem to get the problem, it solely seems to be POP3 that is affected.
Has anyone come across this before? What can I do to diagnose the problem?
netstat shows the connection as being in the established state, but the session isn't actually set up. I had a quick tinker with the prefork values to see f that made any difference but as the connection was established I didn't think it would, and it didn't.
Restarting doesn't seem to immediately cure the problem, but a while after that it comes back to life, then after probably around 20 or so POP3 connections in rapid succession it fails again. I've taken a packet capture from when the fault occurs, but it doesn't reveal anything to me. I've chopped this to remove irrelevant traffic such as smtp, ssh and ntp.
02:33:53.661576 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38281 > delilah.unifiedgroup.co.uk.pop3: S 1220713841:1220713841(0) win 65535 <mss 1402,nop,nop,sackOK>
02:33:53.661612 IP delilah.unifiedgroup.co.uk.pop3 > xxx-xxx-xxx-xxx.dsl.pipex.com.38281: S 265982648:265982648(0) ack 1220713842 win 5840 <mss 1460,nop,nop,sackOK>
02:33:53.697353 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38281 > delilah.unifiedgroup.co.uk.pop3: . ack 1 win 65535
02:34:01.132917 IP samson.unifiedgroup.co.uk.microsoft-ds > delilah.unifiedgroup.co.uk.3087: . 1583174566:1583174567(1) ack 3877690427 win 65027
02:34:01.132979 IP delilah.unifiedgroup.co.uk.3087 > samson.unifiedgroup.co.uk.microsoft-ds: . ack 1 win 1728 <nop,nop,timestamp 46699679 1137810,nop,nop,sack sack 1 {0:1} >
02:35:43.855948 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38285 > delilah.unifiedgroup.co.uk.imap2: S 1521578317:1521578317(0) win 65535 <mss 1402,nop,nop,sackOK>
02:35:43.856014 IP delilah.unifiedgroup.co.uk.imap2 > xxx-xxx-xxx-xxx.dsl.pipex.com.38285: S 379649352:379649352(0) ack 1521578318 win 5840 <mss 1460,nop,nop,sackOK>
02:35:43.891510 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38285 > delilah.unifiedgroup.co.uk.imap2: . ack 1 win 65535
02:35:43.896521 IP delilah.unifiedgroup.co.uk.imap2 > xxx-xxx-xxx-xxx.dsl.pipex.com.38285: P 1:55(54) ack 1 win 5840
02:35:44.080735 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38285 > delilah.unifiedgroup.co.uk.imap2: . ack 55 win 65481
02:35:48.136670 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38285 > delilah.unifiedgroup.co.uk.imap2: F 1:1(0) ack 55 win 65481
02:35:48.136917 IP delilah.unifiedgroup.co.uk.imap2 > xxx-xxx-xxx-xxx.dsl.pipex.com.38285: . ack 2 win 5840
02:35:48.137353 IP delilah.unifiedgroup.co.uk.imap2 > xxx-xxx-xxx-xxx.dsl.pipex.com.38285: F 55:55(0) ack 2 win 5840
02:35:48.175638 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38285 > delilah.unifiedgroup.co.uk.imap2: . ack 56 win 65481
02:35:52.661274 IP delilah.unifiedgroup.co.uk.pop3 > xxx-xxx-xxx-xxx.dsl.pipex.com.38278: P 56067399:56067483(84) ack 826240789 win 5840
02:35:52.662135 IP delilah.unifiedgroup.co.uk.pop3 > xxx-xxx-xxx-xxx.dsl.pipex.com.38278: F 84:84(0) ack 1 win 5840
02:35:52.662816 IP delilah.unifiedgroup.co.uk.pop3 > xxx-xxx-xxx-xxx.dsl.pipex.com.38277: P 53953223:53953307(84) ack 806390175 win 5840
02:35:52.663724 IP delilah.unifiedgroup.co.uk.pop3 > xxx-xxx-xxx-xxx.dsl.pipex.com.38277: F 84:84(0) ack 1 win 5840
02:35:52.664411 IP delilah.unifiedgroup.co.uk.pop3 > xxx-xxx-xxx-xxx.dsl.pipex.com.38276: P 44691622:44691706(84) ack 4084763733 win 5840
02:35:52.665310 IP delilah.unifiedgroup.co.uk.pop3 > xxx-xxx-xxx-xxx.dsl.pipex.com.38276: F 84:84(0) ack 1 win 5840
02:35:52.665561 IP delilah.unifiedgroup.co.uk.pop3 > xxx-xxx-xxx-xxx.dsl.pipex.com.38281: P 1:85(84) ack 1 win 5840
02:35:52.666043 IP delilah.unifiedgroup.co.uk.pop3 > xxx-xxx-xxx-xxx.dsl.pipex.com.38280: P 258057498:258057582(84) ack 3600355369 win 5840
02:35:52.666992 IP delilah.unifiedgroup.co.uk.pop3 > xxx-xxx-xxx-xxx.dsl.pipex.com.38280: F 84:84(0) ack 1 win 5840
02:35:52.699581 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38278 > delilah.unifiedgroup.co.uk.pop3: R 826240789:826240789(0) win 0
02:35:52.708412 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38277 > delilah.unifiedgroup.co.uk.pop3: R 806390175:806390175(0) win 0
02:35:52.714476 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38276 > delilah.unifiedgroup.co.uk.pop3: R 4084763733:4084763733(0) win 0
02:35:52.726493 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38280 > delilah.unifiedgroup.co.uk.pop3: R 3600355369:3600355369(0) win 0
02:35:52.939491 IP xxx-xxx-xxx-xxx.dsl.pipex.com.38281 > delilah.unifiedgroup.co.uk.pop3: . ack 85 win 65451
You can see in the middle there, I established an IMAP connection quickly, to prove that at the time POP3 was the only thing working - that the POP3 connection came back into play straight after is purely co-incidental as it doesn't usually. As you can see by the time stamp, that POP3 session took 2 minutes to establish. The default for Outlook is to warn that there is a server problem after 60 seconds of attempting to connect, so I'm expecting lots of complaints!
cyrus.conf:
START {
recover cmd="ctl_cyrusdb -r"
}
SERVICES {
imap cmd="imapd" listen="imap2" prefork=5
pop3 cmd="pop3d" listen="pop-3" prefork=15
imaps cmd="imapd -s" listen="imaps" prefork=0
pop3s cmd="pop3d -s" listen="pop3s" prefork=0
sieve cmd="timsieved" listen="sieve" prefork=0
#lmtp cmd="lmtpd" listen="lmtp" prefork=0
lmtpunix cmd="lmtpd" listen="/var/imap/socket/lmtp" prefork=0
#notify cmd="notifyd" listen="/var/imap/socket/notify" proto="udp" prefork=1
}
EVENTS {
checkpoint cmd="ctl_cyrusdb -c" period=30
delprune cmd="ctl_deliver -E 3" period=1440
tlsprune cmd="tls_prune" period=1440
}
imapd.conf:
configdirectory: /var/imap
partition-default: /var/spool/imap
sievedir: /var/imap/sieve
tls_ca_path: /etc/ssl/certs
tls_cert_file: /etc/ssl/cyrus/server.crt
tls_key_file: /etc/ssl/cyrus/server.key
admins: root
hashimapspool: yes
allowanonymouslogin: no
allowplaintext: yes
lmtp_downcase_rcpt: yes
sasl_pwcheck_method: saslauthd
sasl_mech_list: LOGIN
The authentication is passed off to Active Directory via PAM hence the use of saslauthd and the use of the login mechanism.
Any help with this would be gratefully recieved!
Regards,
Scott
-------------- next part --------------
An HTML attachment was scrubbed...
URL: https://lists.andrew.cmu.edu/mailman/private/info-cyrus/attachments/20050422/2a7dd7ed/attachment.html
More information about the Info-cyrus
mailing list