All -
We've just recently deployed a Mina-based server (using mina-core-1.0.3) to
production that had been in testing for some time. We are now getting a
strange error that we had never seen during testing.
The server is a fairly simple request / response multi-threaded server that
uses our own custom protocol codec for encoding and decoding messages. The
codec uses a line length to separate initialization messages, and then a
delimiter for all subsequent messages. We use a
edu.emory.mathcs.backport.java.util.concurrent.Executors.newCachedThreadPoolexecutor
with an ExecutorFilter to handle requests in different threads.
The max # of threads is set using the # of processors + 1, as in the mina
tutorial.
We are getting a strange socket connection that is always paired with a
strange java.lang.Integer / java.lang.String mismatch? Additionally, we've
noticed that a new thread is being spawned for each incoming request and
that these threads are no longer returning to the thread pool as they were
during the testing phase. The server runs as a windows service using
JavaService and we are continuously restarting as the memory usage climbs
above 500 MB or so.
We are now getting the following exceptions, sometimes after a single
request, sometimes after 10-15, as extracted from our log files:
2007-09-25 10:28:07,821 [SocketAcceptorIoProcessor-0.3] INFO
<package>.handler.ReceiptTaskHandler - [/56.116.73.225:4630] EXCEPTION:
java.net.SocketException: Connection reset by peer: Read failed
at sun.nio.ch.SocketDispatcher.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:42)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:265)
at sun.nio.ch.IOUtil.read(IOUtil.java:238)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:223)
at org.apache.mina.transport.socket.nio.SocketIoProcessor.read(
SocketIoProcessor.java:267)
at org.apache.mina.transport.socket.nio.SocketIoProcessor.process(
SocketIoProcessor.java:241)
at org.apache.mina.transport.socket.nio.SocketIoProcessor.access$500(
SocketIoProcessor.java:44)
at org.apache.mina.transport.socket.nio.SocketIoProcessor$Worker.run(
SocketIoProcessor.java:563)
at org.apache.mina.util.NamePreservingRunnable.run(
NamePreservingRunnable.java:43)
at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.runWorker(
ThreadPoolExecutor.java:987)
at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run
(ThreadPoolExecutor.java:528)
at java.lang.Thread.run(Thread.java:832)
2007-09-25 10:28:07,821 [SocketAcceptorIoProcessor-0.3] INFO
<package>.handler.ReceiptTaskHandler - [/56.116.73.225:4630] CLOSED
2007-09-25 10:28:07,821 [pool-1-thread-32] ERROR
<package>.handler.ReceiptTaskHandler - [/56.116.73.225:4630] Connection with
client closed abnormally. Exception: Connection reset by peer: Read failed
2007-09-25 10:28:07,836 [pool-1-thread-32] ERROR
<package>.handler.ReceiptTaskHandler - [/56.116.73.225:4630] Connection with
client closed abnormally. Exception: java/lang/Integer incompatible with
java/lang/String
As you can see, this is on the 32nd thread spawned and is the 32nd message
received since the server started. We currently only have a single client
connected to the server.
Has anyone ever seen anything like this before? Any ideas? Thanks in
advance for your help!
Best,
Matt
