Problem with hang on startup when plugin includes Apache lib

Classic Servoy
1

I’ve got a somewhat odd problem that I’ve run across with a custom Servoy plugin I’ve developed, and I was wondering if anyone might be able to shed any light on what might be going wrong or how I could debug it.

Basically, the plugin in question uses the eBay Java SDK, and hence includes the Apache Jakarta lib and AXIS as part of the JAR file. This has worked fine until very recently, but one of either the Mac OS Java update or Servoy update to 3.5.10 has caused something to break.

The symptoms I get post-update are that Servoy (Developer) itself loads, but hangs on the splash screen with “Application Server Init” in the status panel. The system log reports that the VM has run out of memory (log below). Increasing the -Xmx and --launcher.XXMaxPermSize makes the problem take slightly longer to appear (as in it gets as far as “Opening Solution”), but it seems that something is simply eating memory at a colossal rate because even with a couple of Gb available it still dies before getting beyond the loading phase.

Now, what’s curious about this is that if I go into my JAR builder script and remove the Apache libraries, everything works fine - memory usage is within normal bounds, the solution works perfectly… the only hiccup is that (for obvious reasons) my plugin fails when it’s invoked as the libraries aren’t there. The plugin itself just exports a couple of JS functions, so it shouldn’t be doing anything other than the boilerplate plugin init code on startup - certainly nothing that would consume large amounts of RAM, as far as I know.

Suspecting that AXIS might be the problem in some fashion (version-clash?), I tried upgrading to the latest eBay SDK which uses JAXWS, but with exactly the same results. Has anyone got any suggestions as to what might be going wrong here? I’m at a bit of a loss as to why things should suddenly break, or indeed how to debug them since the problem appears to be an incompatibility between Servoy and the libraries, neither of which I can really meaningfully poke about in… any ideas would be greatly appreciated!

Thanks!

Here’s the stack trace from the out-of-memory error:

May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]: java.lang.reflect.InvocationTargetException
May 30 22:49:09: --- last message repeated 1 time ---
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at java.lang.reflect.Method.invoke(Method.java:597)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at com.servoy.j2db.startup.Bootstrap.main(Unknown Source)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at java.lang.reflect.Method.invoke(Method.java:597)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at apple.launcher.LaunchRunner.run(LaunchRunner.java:115)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at apple.launcher.LaunchRunner.callMain(LaunchRunner.java:50)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at apple.launcher.JavaApplicationLauncher.launch(JavaApplicationLauncher.java:52)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]: Caused by: java.lang.OutOfMemoryError: PermGen space
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at java.lang.Class.forName0(Native Method)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at java.lang.Class.forName(Class.java:169)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.x509.OIDMap$OIDInfo.getClazz(OIDMap.java:190)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.x509.OIDMap.getClass(OIDMap.java:273)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.x509.CertificateExtensions.parseExtension(CertificateExtensions.java:79)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.x509.CertificateExtensions.init(CertificateExtensions.java:70)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.x509.CertificateExtensions.<init>(CertificateExtensions.java:60)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.x509.X509CertInfo.parse(X509CertInfo.java:723)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.x509.X509CertInfo.<init>(X509CertInfo.java:152)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.x509.X509CertImpl.parse(X509CertImpl.java:1729)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.x509.X509CertImpl.<init>(X509CertImpl.java:179)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.provider.X509Factory.engineGenerateCertificate(X509Factory.java:90)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at java.security.cert.CertificateFactory.generateCertificate(CertificateFactory.java:305)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.provider.JavaKeyStore.engineLoad(JavaKeyStore.java:746)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.security.provider.JavaKeyStore$JKS.engineLoad(JavaKeyStore.java:38)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at java.security.KeyStore.load(KeyStore.java:1185)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at com.sun.net.ssl.internal.ssl.TrustManagerFactoryImpl.getCacertsKeyStore(TrustManagerFactoryImpl.java:202)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at com.sun.net.ssl.internal.ssl.TrustManagerFactoryImpl.engineInit(TrustManagerFactoryImpl.java:31)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at javax.net.ssl.TrustManagerFactory.init(TrustManagerFactory.java:230)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at com.sun.net.ssl.internal.ssl.SSLContextImpl.engineInit(SSLContextImpl.java:54)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at javax.net.ssl.SSLContext.init(SSLContext.java:248)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at com.servoy.j2db.util.SecuritySupport.getSSLContext(Unknown Source)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at com.servoy.j2db.util.SecuritySupport.getSSLServerSocketFactory(Unknown Source)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at com.servoy.j2db.server.ApplicationServer.a(Unknown Source)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at com.servoy.j2db.server.ApplicationServer.initFromDeveloper(Unknown Source)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at com.servoy.j2db.develop.J2DBDeveloper.dataBaseInit(Unknown Source)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at com.servoy.j2db.develop.J2DBDeveloper.if(Unknown Source)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at com.servoy.j2db.develop.J2DBDeveloper.main(Unknown Source)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
May 30 22:49:09 Kotoko [0x0-0x48c48c].SRVY[70410]:      at java.lang.reflect.Method.invoke(Method.java:597)
May 30 22:49:11 Kotoko [0x0-0x48c48c].SRVY[70410]: Exception in thread "AWT-EventQueue-0" java.lang.OutOfMemoryError: PermGen space
2

i see this:

May 30 22:49:11 Kotoko [0x0-0x48c48c].SRVY[70410]: Exception in thread “AWT-EventQueue-0” java.lang.OutOfMemoryError: PermGen space

so thats a perm gen memory problem
If that is constantly getting eated then that means that somewhere there are constantly classes being created/loaded (thats what perm mem holds)
And those classes are being hold on to (maybe through a classloader) so they are never reclaimed.

3

OK, a quick update on this in case there’s anyone else out there with the same problem, and to see if my deductions are correct…

I’ve debugged into the problem a bit more using Java’s heap tools, and come to the conclusion that the core issue is probably a result of the way Servoy loads plugins - specifically, what I think is going on is that Servoy loads the plugin (including all libraries) using a custom classloader, which then results in a memory leak if one of those classes (java.util.logging.Level being a prime suspect here) adds a reference to itself into something loaded from the base classloader. Internally Servoy seems to be maintaining a big array of all of the classes it finds in the plugin JARs (in com.servoy.j2db.util.n - obviously the name has been obsfucated somewhere along the way), so I wonder if that is also related somehow.

Now, in and of itself that wouldn’t be the end of the world, but it also seems that something in the libraries triggers Servoy into reloading the plugin classes many (possibly an infinite number of) times. Thus, the leak ends up consuming all the available PermGen space… I don’t really know why this would happen, but it fits the observed effect.

At any rate, based on this I decided to try a brute-force solution, and moved all of the libraries out of the plugin and manually placed them in the Servoy lib/ folder, which appears to have fixed everything. It is slightly inconvenient to do this, though, so I was wondering if anyone knows if there’s a better way to separate them such that the plugin loader won’t try to load them all itself?

Thanks again!

4

BenCarter:
OK, a quick update on this in case there’s anyone else out there with the same problem, and to see if my deductions are correct…

I’ve debugged into the problem a bit more using Java’s heap tools, and come to the conclusion that the core issue is probably a result of the way Servoy loads plugins - specifically, what I think is going on is that Servoy loads the plugin (including all libraries) using a custom classloader, which then results in a memory leak if one of those classes (java.util.logging.Level being a prime suspect here) adds a reference to itself into something loaded from the base classloader. Internally Servoy seems to be maintaining a big array of all of the classes it finds in the plugin JARs (in com.servoy.j2db.util.n - obviously the name has been obsfucated somewhere along the way), so I wonder if that is also related somehow.

Now, in and of itself that wouldn’t be the end of the world, but it also seems that something in the libraries triggers Servoy into reloading the plugin classes many (possibly an infinite number of) times. Thus, the leak ends up consuming all the available PermGen space… I don’t really know why this would happen, but it fits the observed effect.

At any rate, based on this I decided to try a brute-force solution, and moved all of the libraries out of the plugin and manually placed them in the Servoy lib/ folder, which appears to have fixed everything. It is slightly inconvenient to do this, though, so I was wondering if anyone knows if there’s a better way to separate them such that the plugin loader won’t try to load them all itself?

Thanks again!

One way to better find the culprit code and the class(es) where this happens would be to install Servoy 5.2b2, then in an Eclipse instance check out the 5.2 sources from the svn branch (see the wiki for installation of the Open Source version) - this way the classes would not be obfuscated and you would better see what’s going on if you launch Servoy in debug mode.

I have no idea if your theory is correct although it looks like it. But putting the plugins in the /lib folder, if this might work in developer on your local machine, will most probably fail on a server with real Smart clients launched from jnlp url, because the jars in lib will not automatically be downloaded by Web Start.

5

Ah, good point - when I get a spare moment I’ll try 5.2 and see what it has to say… since doing that would require the solution to be upgraded it might take a bit of fiddling, but it does seem like the easiest way to investigate further.

And, yep, you’re right about the smart clients as well - fortunately in this specific instance having the plugin working in developer itself is good enough, though, so I’m saved there for now!

Thanks!

6

Which Apache jar is causing this problem BTW? Axis?

7

That’s a good question - it’s one or more of the Apache commons-logging, jakarta-oro, log4j, serialiser or xalan libs, but I’m not entirely sure which (or what combinations). Basically, if I remove all of those then the plugin loads correctly, but most combinations also seem to cause it to fail (I haven’t tried every permutation, but at a minimum removing any single one of the above doesn’t help, nor do most obvious pairs).

I was using Axis before but I updated to the latest eBay SDK, which uses jaxws instead - however, since everything loads fine with the jaxws/jaxp libs included in the JAR, I’m guessing they aren’t the source of the issue.

8

Servoy shouldnt load over and over again the plugin classes. Thats only done once at the startup of a server.

SmartClients dont even use a custom class loader at all, plugins there are loaded through the Webstarts classloader.