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