Starting this morning something very odd has started to happen. After a period of time the server stops sending any kind of message after it sends over the policy file. I've noticed when it is working you get back an apiOK message and then login goes as planned etc. With all logging turned on to the highest level all I see is:
[ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
after a certain period of time. People already logged in are fine but if you try to connect and log in it fails. Obviously the connect works (as does the telnet test) but after that point things just don't go. If I skip waiting for the apiOK message and just try to log in it does every get that message. It's like the client connects sends the one apiversion message gets one message back and then poof the socket is closed.
Any ideas?
FYI - I've been running this for a couple years and this just started today.
Could it be a hacker sending some kill packet?
Socket closed after policy data is sent.
If it helps, this is all I see in the log file once things go haywire. (wrapper logs turned to debug, SFS turned to finest)
INFO | jvm 1 | 2011/12/27 05:53:00 | 05:53:00.449 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:00 | 05:53:00.757 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:01 | 05:53:01.317 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:02 | 05:53:02.017 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:03 | 05:53:03.270 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:03 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:03 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:03 | WrapperManager Debug: Send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:03 | 05:53:03.323 - [ FINE ] > User [ frankbillie ] removed
DEBUG | wrapperp | 2011/12/27 05:53:03 | read a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:03 | 05:53:03.646 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:06 | 05:53:06.905 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:07 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:07 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:07 | WrapperManager Debug: Send a packet PING : ping
DEBUG | wrapperp | 2011/12/27 05:53:07 | read a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:07 | 05:53:07.883 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:08 | 05:53:08.038 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:10 | 05:53:10.646 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:11 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:11 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:11 | WrapperManager Debug: Send a packet PING : ping
DEBUG | wrapperp | 2011/12/27 05:53:11 | read a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:12 | 05:53:12.067 - [ FINE ] > User [ Sandrop ] removed
INFO | jvm 1 | 2011/12/27 05:53:13 | 05:53:12.979 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:15 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:15 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:15 | WrapperManager Debug: Send a packet PING : ping
DEBUG | wrapperp | 2011/12/27 05:53:15 | read a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:16 | 05:53:16.657 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:19 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:19 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:19 | WrapperManager Debug: Send a packet PING : ping
DEBUG | wrapperp | 2011/12/27 05:53:19 | read a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:20 | 05:53:20.670 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:21 | 05:53:21.272 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:23 | 05:53:23.212 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:23 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:23 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:23 | WrapperManager Debug: Send a packet PING : ping
DEBUG | wrapperp | 2011/12/27 05:53:23 | read a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:00 | 05:53:00.449 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:00 | 05:53:00.757 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:01 | 05:53:01.317 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:02 | 05:53:02.017 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:03 | 05:53:03.270 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:03 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:03 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:03 | WrapperManager Debug: Send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:03 | 05:53:03.323 - [ FINE ] > User [ frankbillie ] removed
DEBUG | wrapperp | 2011/12/27 05:53:03 | read a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:03 | 05:53:03.646 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:06 | 05:53:06.905 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:07 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:07 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:07 | WrapperManager Debug: Send a packet PING : ping
DEBUG | wrapperp | 2011/12/27 05:53:07 | read a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:07 | 05:53:07.883 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:08 | 05:53:08.038 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:10 | 05:53:10.646 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:11 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:11 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:11 | WrapperManager Debug: Send a packet PING : ping
DEBUG | wrapperp | 2011/12/27 05:53:11 | read a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:12 | 05:53:12.067 - [ FINE ] > User [ Sandrop ] removed
INFO | jvm 1 | 2011/12/27 05:53:13 | 05:53:12.979 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:15 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:15 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:15 | WrapperManager Debug: Send a packet PING : ping
DEBUG | wrapperp | 2011/12/27 05:53:15 | read a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:16 | 05:53:16.657 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:19 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:19 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:19 | WrapperManager Debug: Send a packet PING : ping
DEBUG | wrapperp | 2011/12/27 05:53:19 | read a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:20 | 05:53:20.670 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:21 | 05:53:21.272 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
INFO | jvm 1 | 2011/12/27 05:53:23 | 05:53:23.212 - [ FINE ] > User [ java.nio.channels.SocketChannel[closed] ] removed
DEBUG | wrapperp | 2011/12/27 05:53:23 | send a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:23 | WrapperManager Debug: Received a packet PING : ping
INFO | jvm 1 | 2011/12/27 05:53:23 | WrapperManager Debug: Send a packet PING : ping
DEBUG | wrapperp | 2011/12/27 05:53:23 | read a packet PING : ping
