ES5 stops accepting connections

[gamesrfun]

Yesterday our server stopped accepting client connections (the admin console still works, and we can ssh into the server still). Prior to this, the server had run with the same client load for about 3 weeks without a hitch.

This morning we rebooted the server and it was running fine at first, but after an hour it stopped accepting connections again. However, the clients who were already connected continued playing until their games ended.

While there was no exception logged last night, today I found the following error in the log file around the time that connections started being refused. Any ideas on what could be the problem behind all this? Thanks!

2012-May-24 10:14:00:989 [pool-4-thread-1] ERROR com.electrotank.electroserver5.DefaultExceptionHandler  - Uncaught exception
java.lang.InternalError
	at sun.misc.URLClassPath$JarLoader.getResource(Unknown Source)
	at sun.misc.URLClassPath.getResource(Unknown Source)
	at java.net.URLClassLoader$1.run(Unknown Source)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.net.URLClassLoader.findClass(Unknown Source)
	at sun.misc.Launcher$ExtClassLoader.findClass(Unknown Source)
	at java.lang.ClassLoader.loadClass(Unknown Source)
	at java.lang.ClassLoader.loadClass(Unknown Source)
	at sun.misc.Launcher$AppClassLoader.loadClass(Unknown Source)
	at java.lang.ClassLoader.loadClass(Unknown Source)
	at java.util.ResourceBundle$RBClassLoader.loadClass(Unknown Source)
	at java.util.ResourceBundle$Control.newBundle(Unknown Source)
	at java.util.ResourceBundle.loadBundle(Unknown Source)
	at java.util.ResourceBundle.findBundle(Unknown Source)
	at java.util.ResourceBundle.findBundle(Unknown Source)
	at java.util.ResourceBundle.getBundleImpl(Unknown Source)
	at java.util.ResourceBundle.getBundle(Unknown Source)
	at java.util.logging.Level.getLocalizedName(Unknown Source)
	at java.util.logging.SimpleFormatter.format(Unknown Source)
	at java.util.logging.StreamHandler.publish(Unknown Source)
	at java.util.logging.ConsoleHandler.publish(Unknown Source)
	at java.util.logging.Logger.log(Unknown Source)
	at java.util.logging.Logger.doLog(Unknown Source)
	at java.util.logging.Logger.logp(Unknown Source)
	at org.jboss.netty.logging.JdkLogger.warn(JdkLogger.java:80)
	at org.jboss.netty.logging.InternalLoggerFactory$1.warn(InternalLoggerFactory.java:128)
	at org.jboss.netty.channel.socket.nio.NioServerSocketPipelineSink$Boss.run(NioServerSocketPipelineSink.java:251)
	at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:102)
	at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
Caused by: java.util.zip.ZipException: error in opening zip file
	at java.util.zip.ZipFile.open(Native Method)
	at java.util.zip.ZipFile.<init>(Unknown Source)
	at java.util.jar.JarFile.<init>(Unknown Source)
	at java.util.jar.JarFile.<init>(Unknown Source)
	at sun.misc.URLClassPath$JarLoader.getJarFile(Unknown Source)
	at sun.misc.URLClassPath$JarLoader.access$600(Unknown Source)
	at sun.misc.URLClassPath$JarLoader$1.run(Unknown Source)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.misc.URLClassPath$JarLoader.ensureOpen(Unknown Source)
	... 32 more

[tcarr]

It's having problems opening a zip file. I don't see any com.electroserver lines in the log snippet above, so I assume we have one of these situations:
1. One of the plugins in your extension is trying to read a zip file, and the zip file is either missing or corrupted.
2. You have ES Admin's General Settings set with a "Message size compression threshold" that is not -1.

Do either of these apply to your project? I assume that you are already on 5.3.2; if you aren't then upgrading should help.

[tcarr]

Oh one other possibility: was anybody using ES Admin to upload a zipped extension at the time of the error in the logs?

[gamesrfun]

I think the zip call is happening by virtue of the system trying to open a jar file (which are really zip files). We don't have any code that deals with zip files, nor were uploading extensions (we don't even use zipped extensions), and I also checked that message compression is -1.

The exception looks like it could be caused by this issue - wasn't netty added recently? The stacktrace here is practically identical.
https://bugzilla.redhat.com/show_bug.cgi?id=745866


This may explain why it died again this morning, but since this error did not appear in the logs last night I don't know what caused that first problem. Have you seen electroserver refuse connections under other circumstances?

[tcarr]

Oh good catch! Yes, Netty was added in the 5.3.2 release. If we can track down a jar that has the missing logging functions that Netty needs to log the error message, we can add it to server/lib and it will keep THAT error from recurring.

When ElectroServer refuses connections, for the 5.3.2 release, the most likely problem is that the ES Admin's General Settings still has a max concurrent user set to 50, or that the number of ccu has met the license's limit.

Can you confirm that ES5 is actually refusing the connection when this happens? It's far more common for a problem with a database to prevent users logging in, if you have a login event handler that needs a database connection.

[tcarr]

Question: which version of JVM are you using with ES5? We test using Java 1.6, not 1.7, and the JRE that we ship with installers that include a JRE does have the jar file that Netty bugzilla ticket refers to.

[gamesrfun]

Our license is unlimited and max CCU is 100000. Server reports java version 1.6.0_30, which was downloaded from Sun (the unix install of ElectroServer 5.3.2 that I downloaded didn't include a JRE).

I stepped through with my client and always got a failed ConnectionResponse, so I'm sure it's a connection problem. The loginhandler also doesn't access a database.

It's odd, I dug into the RT.jar on the server and found the "missing" class too! I also can confirm in the log file that electroserver starts with the correct JRE (I explicitly export the JRE path to the variable INSTALL4J_JAVA_HOME).

[tcarr]

Very strange indeed. I'll see if we can figure out what is causing the problem.

[tcarr]

Jason says you "have either run out of memory or file handles. Since the existing users were able to keep playing, I'd guess file handles. If they are running on UNIX they'll want to use ulimit to increase the number of file handles available to the user running the server. Most likely they have either had a recent increase in CCU (causing more file handles to be open at once) or they are somehow leaking a file handle in their code."

Let me know if you need info on how to use ulimit, and I'll dig out the instructions on that.

[gamesrfun]

I've done some configuration with ulimit and have nofiles set to 250000 (same reported in sysctl files-max and security/limits.conf). I didn't however check to see how many files were open when this error happened, so if/when it happens again I will try that. Maybe there's a leak.

If you have any special instructions on ulimit, I'd like to take a look at that too. Thanks!