Last night I encountered something which sounds a bit like what has been described
below, however, in putting the logs together below I note the fault appeared to start
during receipt of an email by SMTP. I'm running James 1.2 on MacOS X Beta (roughly
Java 1.2.2 + Hotspot).
Everything was working fine for 24 hours (I installed Monday evening).
Last night I tried to download my email by POP3 and was refused login. I'll refer to
this situation as 'the fault'.
Here is all the information (relevant or irrelevant) that I have gathered:
Logging in using the admin facility still appears to work after the 'the fault'. The
'help' command responds correctly, but 'listusers' doesn't work and hangs. If I
restart James 'listusers' works again.
Looking at the logs I notice a line in avalon.log which may coincide with 'the fault':
2000.11.22 09:40:07 193 (ERROR) from Avalon: .getBlock: Exception in block null init:
null
Looking at jamesfile.log there is a clear point when 'the fault' starts. Here is the
trace just before and then into the errors that repeat many times a second at various
intervals (perhaps coinciding with the arrival of mail by SMTP):
2000.11.22 12:45:59 266 (INFO) from Processor: ==== Begin processing mail
Mail974853959111-2697 ====
2000.11.22 12:45:59 281 (INFO) from Processor: Processed Mail974853959111-2697 through
transport
2000.11.22 12:45:59 282 (INFO) from Processor: Result was ghost
2000.11.22 12:45:59 350 (INFO) from Processor: ==== Removed from spool mail
Mail974853959111-2697 ====
2000.11.22 12:51:49 372 (ERROR) from Processor: Exception in JamesSpoolManager.run
null
2000.11.22 12:51:49 388 (ERROR) from Processor: Exception in JamesSpoolManager.run
null
Looking at netfile.log there appears to be a clear problem occuring with the number of
open files. The first fault I can find occurs during receipt of an email by James
(SMTP):
2000.11.22 12:51:48 788 (INFO) from SMTP: Command received: EHLO relaysmtp.digiweb.com
2000.11.22 12:51:48 909 (INFO) from SMTP: Command received: MAIL
From:<[EMAIL PROTECTED]>
2000.11.22 12:51:49 028 (INFO) from SMTP: Command received: RCPT
To:<[EMAIL PROTECTED]>
2000.11.22 12:51:49 148 (INFO) from SMTP: Command received: DATA
2000.11.22 12:51:49 344 (ERROR) from SMTP: Error processing message: Exception
spooling message: Exception caught while storing Message Container:
java.lang.RuntimeException: Exception caught while storing a stream:
java.io.FileNotFoundException:
../var/mail/spool/4D61696C3937343835343330393332332D32363939.private.StreamStore (Too
many open files)
From this point on the log file appears to contain the full text of the email
received. Presumably it has got out of sync with receiving commands and is taking
every line of the email as an SMTP command. The 'too many open files' fault appears
to reoccur for every email received.
Then, having restarted James, there is what appears to be a related fault during an
attempt to download email (by POP3). Here's an anonymised log of a POP3 connection
exhibiting 'the fault':
2000.11.22 09:40:07 017 (INFO) from POP3: Connection from mailclient (192.168.xxx.xxx)
2000.11.22 09:40:07 039 (INFO) from POP3: Command recieved: USER stuart.roebuck
2000.11.22 09:40:07 045 (INFO) from POP3: Command recieved: PASS xxxx
2000.11.22 09:40:07 100 (INFO) from POP3: Connection from mailclient (192.168.xxx.xxx)
2000.11.22 09:40:07 116 (INFO) from POP3: Command recieved: USER postmaster
2000.11.22 09:40:07 118 (INFO) from POP3: Command recieved: PASS xxxx
2000.11.22 09:40:08 097 (INFO) from POP3: Command recieved: STAT
2000.11.22 09:40:08 872 (INFO) from POP3: Command recieved: LIST
2000.11.22 09:40:08 948 (INFO) from POP3: Command recieved: UIDL
2000.11.22 09:40:09 148 (INFO) from POP3: Command recieved: QUIT
2000.11.22 09:40:09 156 (INFO) from POP3: Connection closed
2000.11.22 09:40:23 425 (ERROR) from POP3: Exception during connection from mailclient
(192.168.xxx.xxx) : Exception caught while retrieving an object:
java.io.FileNotFoundException:
../var/mail/localinbox/stuart/roebuck/4D61696C3937343835303130383531332D32353335.private.PersistentStore
(Too many open files)
Stuart.
> Charles I am using 1.2 and it is still causing the problem.
> It also occurs on
>ordinary email, it affects pop dnloads and the
> outgoing mail. The lack of <CRLF> on
>the end of a message with a not
> empty final line causes the system to hang (only
>tested with netscape NT
> client) when pop dnloading. I think this also may be
>contributing to the
> file delete problems with NT. When a pop dnload is cancelled
>due to it
> hanging, the file handle is still kept in the operation system
>
>preventing the file from been deleted.
>
> What appears to be the problem is that
>the CharTerminatedInputStream
> class is consuming the <CRLF>.<CRLF> at the end of
>the message. It needs
> to leave the the first <CRLF> or even the whole <CRLF>.<CRLF>
>at the
> expense of an extra . in the message. I below is a solution I am
> working
>on that does not consume the <CRLF>.<CRLF> I have not had a
> chance to test it yet,
>you may want to try it though.
>
> pb..
>
>
> <code
>filename=3D"CharTerminatedInputStream2.java">
>
> package org.apache.james.util;
-------------------------------------------------------------------------
Stuart Roebuck, BSc, MBA Tel.: 0131 228 4853 / Fax.: 0870 054 8322
Managing Director Alpha Numeric Pager: 07654 588898
ADOLOS http://www.adolos.com/
------------------------------------------------------------
To subscribe: [EMAIL PROTECTED]
To unsubscribe: [EMAIL PROTECTED]
Archives: <http://www.mail-archive.com/james%40list.working-dogs.com/>
Problems?: [EMAIL PROTECTED]
