terminated abnormally

[Patrick Radtke]

On Mar 23, 2006, at 8:27 AM, Ken Murchison wrote:

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


Hmm.   That seems to happen on all our connections.
Mar 23 02:00:14 tempeh imaps[5651]: starttls: TLSv1 with cipher RC4- 
MD5 (128/128 bits new) no authentication
Mar 23 02:00:14 tempeh imaps[5651]: login:  
dyn-128-59-150-148.dyn.columbia.edu [128.59.150.148] yc587 plaintext+TLS
Mar 23 02:00:14 tempeh imaps[5651]: failed to bind to address  
128.59.48.36: Cannot assign requested address
Mar 23 02:00:14 tempeh imaps[5651]: Doing a peer verify
Mar 23 02:00:14 tempeh imaps[5651]: Doing a peer verify
Mar 23 02:00:14 tempeh imaps[5651]: starttls: TLSv1 with cipher  
AES256-SHA (256/256 bits new) no authentication

We apply a starttls patch to our builds but it looks like the patch  
only affects the perl libraries and sieve.
I'll try to find out why it does the double auth on our test machines.

Thanks for the tip!

-Patrick