Patrick Radtke wrote:
Every day we get a number of 'terminated abnormally' messages on our
frontends.
When they happen just occasionally then everything still seems to run fine.
However sometimes, there will be a large number of them in a short time
span and this is a sure sign that people are having trouble logging in
or are being disconnected.
here is examples from the log
Mar 22 10:50:07 tofu master[19506]: service pop3s pid 18311 in READY
state: terminated abnormally
Mar 22 10:50:10 tofu master[19506]: service imaps pid 18128 in READY
state: terminated abnormally
Mar 22 10:50:20 tofu master[19506]: service imaps pid 18348 in READY
state: terminated abnormally
Mar 22 10:50:23 tofu master[19506]: service imaps pid 13063 in READY
state: terminated abnormally
Mar 22 10:50:32 tofu master[19506]: service pop3s pid 18404 in READY
state: terminated abnormally
Mar 22 10:50:33 tofu master[19506]: service pop3s pid 18218 in READY
state: terminated abnormally
Mar 22 11:01:42 valoney master[2581]: service imaps pid 25617 in READY
state: terminated abnormally
Mar 22 11:01:46 valoney master[2581]: service pop3s pid 25682 in READY
state: terminated abnormally
Mar 22 11:01:47 valoney master[2581]: service imaps pid 25903 in READY
state: terminated abnormally
searching on just a fail process id shows
Mar 22 11:01:38 valoney imaps[25903]: imaps failed: [local]
Mar 22 11:01:47 valoney master[2581]: service imaps pid 25903 in READY
state: terminated abnormally
Mar 22 11:01:51 valoney master[2581]: service imaps pid 25903: while
trying to process message 0x2: not registered yet
Mar 22 11:01:52 valoney master[2581]: service imaps pid 25903 in UNKNOWN
state: processing message 0x2
ar 22 11:01:04 valoney pop3s[25440]: starttls: TLSv1 with cipher RC4-MD5
(128/128 bits new) no authentication
Mar 22 11:01:20 valoney pop3s[25440]: login:
pool-141-155-147-109.ny5030.east.verizon.net [141.155.147.109] jg2378
plaintext+TLS User logged in
Mar 22 11:01:21 valoney pop3s[25440]: failed to bind to address
128.59.48.36: Cannot assign requested address
Mar 22 11:01:21 valoney pop3s[25440]: Doing a peer verify
Mar 22 11:01:21 valoney pop3s[25440]: Doing a peer verify
Mar 22 11:01:21 valoney pop3s[25440]: starttls: TLSv1 with cipher
AES256-SHA (256/256 bits new) no authentication
Mar 22 11:01:36 valoney pop3s[25440]: pop3s failed: [local]
Mar 22 11:01:37 valoney pop3s[25440]: Fatal error: tls_start_servertls()
failed
Mar 22 11:01:41 valoney master[2581]: service pop3s pid 25440 in READY
state: terminated abnormally
Mar 22 11:01:52 valoney master[2581]: service pop3s pid 25440: while
trying to process message 0x2: not registered yet
Mar 22 11:01:52 valoney master[2581]: service pop3s pid 25440 in UNKNOWN
state: processing message 0x2
I've never seen behavior like this before. You have a pop3d which looks
like it successfully does TLS+PLAIN, but then attempts TLS again. What
I don't know is if the client has disconnected in between, or if there
is some kind of race condition.
--
Kenneth Murchison
Project Cyrus Developer/Maintainer
Carnegie Mellon University
----
Cyrus Home Page: http://asg.web.cmu.edu/cyrus
Cyrus Wiki/FAQ: http://cyruswiki.andrew.cmu.edu
List Archives/Info: http://asg.web.cmu.edu/cyrus/mailing-list.html
