This problem has still not gone away for us, though recently it has
only been taking 30-45 to restart James. We try not to restart James
at all, but this morning we had to for an emergency server/network
reconfiguration. As I write this I am still waiting for James to wake
up. I have DEBUG on, and here is the tail of the smtpserver log:
----------------------- line 1118 -----------------------
22/04/06 12:40:15 DEBUG smtpserver: Watchdog default Worker #84 has
time to sleep -147
22/04/06 12:40:15 ERROR smtpserver: SMTP Connection has idled out.
22/04/06 12:40:15 DEBUG smtpserver: Watchdog default Worker #84 is
exiting run().
22/04/06 12:40:15 DEBUG smtpserver: Watchdog default Worker #85 has
time to sleep -71
22/04/06 12:40:15 ERROR smtpserver: SMTP Connection has idled out.
22/04/06 12:40:15 DEBUG smtpserver: Watchdog default Worker #85 is
exiting run().
22/04/06 12:40:17 DEBUG smtpserver: Watchdog default Worker #87 has
time to sleep -78
22/04/06 12:40:17 ERROR smtpserver: SMTP Connection has idled out.
22/04/06 12:40:17 DEBUG smtpserver: Watchdog default Worker #87 is
exiting run().
22/04/06 12:40:29 DEBUG smtpserver: Watchdog default Worker #88 has
time to sleep -75
22/04/06 12:40:29 ERROR smtpserver: SMTP Connection has idled out.
22/04/06 12:40:29 DEBUG smtpserver: Watchdog default Worker #88 is
exiting run().
------------------------ EOF -----------------------
Note that we restarted James at 22/04/06 12:28:39, and now the time is
22/04/06 13:05:08. So I'm guessing we have another 10 minutes or so to
wait before James spits out a string of these errors and starts
handling smtp/pop again (from a previous restart):
----------------------- line 1816 -----------------------
18/04/06 04:15:01 DEBUG smtpserver: Watchdog default Worker #66 has
time to sleep -83
18/04/06 04:15:01 ERROR smtpserver: SMTP Connection has idled out.
18/04/06 04:15:01 DEBUG smtpserver: Watchdog default Worker #66 is
exiting run().
18/04/06 04:48:27 ERROR smtpserver: Unknown error occurred while
processing DATA.
javax.mail.MessagingException: Unable to retrieve the data: Socket closed;
nested exception is:
java.net.SocketException: Socket closed
at
org.apache.james.core.MimeMessageInputStreamSource.<init>(MimeMessageInputStreamSource.java:76)
at org.apache.james.core.MailImpl.<init>(MailImpl.java:142)
at
org.apache.james.smtpserver.SMTPHandler.processMail(SMTPHandler.java:1437)
at
org.apache.james.smtpserver.SMTPHandler.doDATA(SMTPHandler.java:1289)
at
org.apache.james.smtpserver.SMTPHandler.parseCommand(SMTPHandler.java:589)
at
org.apache.james.smtpserver.SMTPHandler.handleConnection(SMTPHandler.java:358)
at
org.apache.james.util.connection.ServerConnection$ClientConnectionRunner.run(ServerConnection.java:417)
at
org.apache.james.util.thread.ExecutableRunnable.execute(ExecutableRunnable.java:55)
at
org.apache.james.util.thread.WorkerThread.run(WorkerThread.java:90)
18/04/06 04:48:27 DEBUG smtpserver: Sent: 451 Error processing
message: Unable to retrieve the data: Socket closed;
nested exception is:
java.net.SocketException: Socket closed
18/04/06 04:48:27 DEBUG smtpserver: Calling reset() for inactive watchdog
18/04/06 04:48:27 ERROR smtpserver: Socket to
bb220-255-153-237.singnet.com.sg (220.255.153.237) closed remotely.
java.net.SocketException: Socket closed
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at
java.io.BufferedInputStream.read1(BufferedInputStream.java:220)
at java.io.BufferedInputStream.read(BufferedInputStream.java:277)
at
sun.nio.cs.StreamDecoder$CharsetSD.readBytes(StreamDecoder.java:408)
at
sun.nio.cs.StreamDecoder$CharsetSD.implRead(StreamDecoder.java:450)
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:182)
at java.io.InputStreamReader.read(InputStreamReader.java:167)
at java.io.BufferedReader.fill(BufferedReader.java:136)
at java.io.BufferedReader.read(BufferedReader.java:157)
at
org.apache.james.util.CRLFTerminatedReader.readLine(CRLFTerminatedReader.java:98)
at
org.apache.james.smtpserver.SMTPHandler.readCommandLine(SMTPHandler.java:505)
at
org.apache.james.smtpserver.SMTPHandler.handleConnection(SMTPHandler.java:358)
at
org.apache.james.util.connection.ServerConnection$ClientConnectionRunner.run(ServerConnection.java:417)
at
org.apache.james.util.thread.ExecutableRunnable.execute(ExecutableRunnable.java:55)
at
org.apache.james.util.thread.WorkerThread.run(WorkerThread.java:90)
18/04/06 04:48:27 DEBUG smtpserver: Calling disposeWatchdog() for
inactive watchdog
18/04/06 04:48:27 DEBUG smtpserver: Returning SMTPHandler to pool.
18/04/06 04:48:27 DEBUG smtpserver: Returning a
org.apache.james.smtpserver.SMTPHandler to the pool
----------------------- etc -----------------------
Meanwhile, the "connections" log is going nuts, writing the same set
of "Maximum number of open connections exceeded - refusing connection"
messages over and over at a rate of 10MB per 3 minutes or so:
-rw-r--r-- 1 root root 10485738 Apr 22 12:38
connections-2006-04-22-12-28.log
-rw-r--r-- 1 root root 10485901 Apr 22 12:42
connections-2006-04-22-12-38.log
-rw-r--r-- 1 root root 10485974 Apr 22 12:46
connections-2006-04-22-12-42.log
-rw-r--r-- 1 root root 10485856 Apr 22 12:49
connections-2006-04-22-12-46.log
-rw-r--r-- 1 root root 10485895 Apr 22 12:53
connections-2006-04-22-12-49.log
-rw-r--r-- 1 root root 10485957 Apr 22 12:56
connections-2006-04-22-12-53.log
-rw-r--r-- 1 root root 10485832 Apr 22 12:58
connections-2006-04-22-12-56.log
-rw-r--r-- 1 root root 10485985 Apr 22 13:01
connections-2006-04-22-12-58.log
-rw-r--r-- 1 root root 10485979 Apr 22 13:03
connections-2006-04-22-13-01.log
-rw-r--r-- 1 root root 10485818 Apr 22 13:04
connections-2006-04-22-13-03.log
-rw-r--r-- 1 root root 10485955 Apr 22 13:06
connections-2006-04-22-13-04.log
-rw-r--r-- 1 root root 10485911 Apr 22 13:08
connections-2006-04-22-13-06.log
-rw-r--r-- 1 root root 10485815 Apr 22 13:11
connections-2006-04-22-13-08.log
-rw-r--r-- 1 root root 8468986 Apr 22 13:13
connections-2006-04-22-13-11.log
Time now is Apr 22 13:13.
I've got netstat dumps if anyone wants to take a look.
I was right about it taking 10 more minuts or so, as I type, James
just woke up.
Anybody got any clue?
Thanks,
Nathan
---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]
