After restarting the application: UnsatisfiedLinkError Native Library jnidispatch.dll already loaded in another classloader

Jul 20, 2010 at 5:47 PM

When using waffle with the NegotiateSecurityFilter I have the problem, that after restarting my application with the Tomcat Application Manager, I get an UnsatisfiedLinkError: Native Library jnidispatch.dll already loaded in another classloader

My setup is the following: The 4 jars commons-logging-1.1.1.jar, jna.jar, platform.jar, waffle-jna.jar are locally deployed in WEB-INF/lib. I'm using Apache Tomcat/6.0.28.

At the first call after starting the Tomcat process, everything works as expected. When I stop and start the webapp with the Tomcat Application Manager I get the UnsatisfiedLinkError. So I have to restart the whole Tomcat process to make it working again.

I have found a workaround by copying the 3 jars commons-logging-1.1.1.jar, jna.jar, platform.jar directly to tomcat's /lib directory and removing them from the webapp directory, but I would prefer to deploy them for the webapp.

The strange thing (what gives me hope) is that I have successfully tested it with the waffle-filter sample app. I have added the 4 jars and stopped and started it with the Tomcat Application Manager several times and it keeps working. So generally having the 4 jars in the WEB-INF/lib directory should work.

Here is the stacktrace I'm getting when calling the application (localhost.log):

20.07.2010 17:57:09 org.apache.catalina.core.StandardWrapperValve invoke
SCHWERWIEGEND: Servlet.service() for servlet jsp threw exception
java.lang.UnsatisfiedLinkError: Native Library C:\Tomcat6.0\work\Catalina\localhost\rr_test\loader\com\sun\jna\win32-amd64\jnidispatch.dll already loaded in another classloader
 at java.lang.ClassLoader.loadLibrary0(ClassLoader.java:1768)
 at java.lang.ClassLoader.loadLibrary(ClassLoader.java:1699)
 at java.lang.Runtime.load0(Runtime.java:770)
 at java.lang.System.load(System.java:1003)
 at com.sun.jna.Native.loadNativeLibraryFromJar(Native.java:761)
 at com.sun.jna.Native.loadNativeLibrary(Native.java:685)
 at com.sun.jna.Native.<clinit>(Native.java:109)
 at com.sun.jna.Pointer.<clinit>(Pointer.java:42)
 at com.sun.jna.platform.win32.WinNT$HANDLEByReference.<init>(WinNT.java:829)
 at com.sun.jna.platform.win32.WinNT$HANDLEByReference.<init>(WinNT.java:825)
 at waffle.windows.auth.impl.WindowsAuthProviderImpl.logonDomainUserEx(Unknown Source)
 at waffle.windows.auth.impl.WindowsAuthProviderImpl.logonDomainUser(Unknown Source)
 at waffle.windows.auth.impl.WindowsAuthProviderImpl.logonUser(Unknown Source)
 at waffle.servlet.spi.BasicSecurityFilterProvider.doFilter(Unknown Source)
 at waffle.servlet.spi.SecurityFilterProviderCollection.doFilter(Unknown Source)
 at waffle.servlet.NegotiateSecurityFilter.doFilter(Unknown Source)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
 at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:861)
 at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:579)
 at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1584)
 at java.lang.Thread.run(Thread.java:619)
20.07.2010 17:57:12 org.apache.catalina.core.StandardWrapperValve invoke
SCHWERWIEGEND: Servlet.service() for servlet jsp threw exception
java.lang.NoClassDefFoundError: Could not initialize class com.sun.jna.Pointer
 at com.sun.jna.platform.win32.WinNT$HANDLEByReference.<init>(WinNT.java:829)
 at com.sun.jna.platform.win32.WinNT$HANDLEByReference.<init>(WinNT.java:825)
 at waffle.windows.auth.impl.WindowsAuthProviderImpl.logonDomainUserEx(Unknown Source)
 at waffle.windows.auth.impl.WindowsAuthProviderImpl.logonDomainUser(Unknown Source)
 at waffle.windows.auth.impl.WindowsAuthProviderImpl.logonUser(Unknown Source)
 at waffle.servlet.spi.BasicSecurityFilterProvider.doFilter(Unknown Source)
 at waffle.servlet.spi.SecurityFilterProviderCollection.doFilter(Unknown Source)
 at waffle.servlet.NegotiateSecurityFilter.doFilter(Unknown Source)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
 at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:861)
 at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:579)
 at org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1584)
 at java.lang.Thread.run(Thread.java:619)

I have just noticed that there is another error in catalina.log when stopping the webapp:

20.07.2010 18:35:10 org.apache.catalina.loader.WebappClassLoader clearReferencesJdbc
SCHWERWIEGEND: The web application [/rr_test] registered the JBDC driver [oracle.jdbc.driver.OracleDriver] but failed to unregister it when the web application was stopped. To prevent a memory leak, the JDBC Driver has been forcibly unregistered.
20.07.2010 18:35:10 org.apache.catalina.loader.WebappClassLoader clearThreadLocalMap
SCHWERWIEGEND: The web application [/rr_test] created a ThreadLocal with key of type [com.sun.jna.Structure$1] (value [com.sun.jna.Structure$1@11b9d4d8]) and a value of type [java.util.HashMap] (value [{}]) but failed to remove it when the web application was stopped. This is very likely to create a memory leak.

I don't get this error when stopping the waffle-filter sample app. Is it possible that the "clearReferencesJdbc" has a negative impact for jna? There is also a "clearReferencesThreads" called before which has problems stopping a thread which has something to do with log4j I believe.

Maybe you have seen this error before and have a quick tip for me where to look to solve it (even without knowing the specifics of my application ;-)).

Coordinator
Jul 21, 2010 at 6:47 PM

First, JNA 3.2.7 just shipped and has some kind of possibly related fix. Lets try it first - I just uploaded a Waffle 1.3, which I am hoping to be the shipping build. Get it and make sure to replace jna.jar and platform.jar in your Tomcat.

I assume the problem will persist. It looks like JNA didn't (re)load. There's this thread where Tim (JNA) explains how the classloaders affect JNA, it may be helpful. Then, post this exact same explanation above to the JNA list (users@jna.dev.java.net). Someone better qualified will surely help.

Jul 21, 2010 at 11:15 PM

I have tried JNA 3.2.7 but sadly the problem is still there. I have just installed Tomcat 7 to take a look how the problem is handled there, but it get's worse. Same scenario as before. I activate NegotiateSecurityFilter, call my application and stop it with the tomcat manager. catalina.log shows this error message:

21.07.2010 23:41:54 org.apache.catalina.loader.WebappClassLoader clearThreadLocalMap
SCHWERWIEGEND: The web application [/rr_test] created a ThreadLocal with key of type [com.sun.jna.Structure$1] (value [com.sun.jna.Structure$1@47a5f7d3]) and a value of type [java.util.HashMap] (value [{}]) but failed to remove it when the web application was stopped. This is very likely to create a memory leak.

But if start the application again, Tomcat 7 doesn't want that anymore and shows in the manager.log:

SCHWERWIEGEND: FAIL - Application at context path /rr_test could not be started
LifecycleException:  An invalid Lifecycle transition was attempted ([before_start]) for component [StandardEngine[Catalina].StandardHost[localhost].StandardContext[/rr_test]] in state [STOPPING]
 at org.apache.catalina.util.LifecycleBase.invalidTransition(LifecycleBase.java:320)
 at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:132)
 at org.apache.catalina.manager.ManagerServlet.start(ManagerServlet.java:1248)
 at org.apache.catalina.manager.HTMLManagerServlet.start(HTMLManagerServlet.java:744)
 at org.apache.catalina.manager.HTMLManagerServlet.doPost(HTMLManagerServlet.java:219)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:641)
 at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:243)
 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:201)
 at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:563)
 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:163)
 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:108)
 at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:556)
 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:402)
 at org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:310)
 at org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:575)
 at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:1555)
 at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
 at java.lang.Thread.run(Thread.java:619)

I think the problem is the same, but now the error "Native Library jnidispatch.dll already loaded in another classloader" - shown with Tomcat 6 - is nowhere displayed in the Tomcat 7 logfiles.

As an additional test I have put the 4 "waffle jars" directly to tomcat/lib (removed them from the WEB-INF/lib/), but now my webapp is not even starting at the first time.

Side note: The waffe-filter example makes no problems and works. With a deactivated NegotiateSecurityFilter my webapp also works. I'm a little bit confused. I have to continue this investigation later. Maybe I made an error with the Tomcat 7 tests.

Jul 22, 2010 at 10:38 AM

Okay, at least the Tomcat 7 problem (my application didn't even start) with the waffle jars globally deployed in /lib is solved. The tomcat log said:

SCHWERWIEGEND: Exception starting filter SecurityFilter
org.apache.commons.logging.LogConfigurationException: org.apache.commons.logging.LogConfigurationException: org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy.  You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed.

The problem was, that in my /WEB-INF/lib directory was a commons-logging.jar version 1.0.4. If I replace this jar with commons-logging.jar version 1.1.1 it's okay to have one commons-logging.jar in /bin and one commons-logging.jar in /WEB-INF/lib.

So the current state is:

1) Everything works with the "waffle jars" (commons-logging-1.1.1.jar, jna.jar, platform.jar, waffle-jna.jar) globally deplayed in the /lib directory

2) The "waffle jars" jars locally deployed works only the first time the tomcat process is started. It's not possible to restart the application with the tomcat manager. The shown error is different for tomcat 6 and tomcat 7.

Jul 22, 2010 at 11:06 AM

Just one more thing. The following scenario works

/lib -> platform.jar, jna.jar

/WEB-INF/lib -> waffle-jna.jar commons-logging.jar

Could that be a valid deployment strategy? I want at least to minimize the globally deployed jars. If I put waffle-jna.jar to /lib I have to put commons-logging.jar there too. How dependent is waffle-jna.jar from jna.jar? When you release a new version of waffle-jna.jar is it always necessary to update jna.jar as well, or are the jna.jar updates rare?

Coordinator
Jul 22, 2010 at 11:26 AM

I asked the JNA list. Here's what they had to say: "in order to unload JNA, the class loader which loads the JNA classes must be GC'd, which doesn't appear to be happening here, perhaps because of the ThreadLocal reference". And "what I've seen most commonly done is to have the web app load JNA in a shared class loader rather than loading and unloading it".

So now it all makes sense and explains why it works when you put jna.jar/platform.jar in Tomcat's lib. Tomcat has a class loader for JARs that live in its lib. Then it has a class loader for each web-app. When you unload a web-app, libraries that Tomcat loaded obviously don't get unloaded.

This is a totally valid deployment scenario. JNA is providing the Win32 API interface, so it changes "more rarely" compared to Waffle, in theory. But we can't predict the future :) I think you should go with this.

I'll create a work-item around this unloading problem. It's possible that the filter can do something explicit in destroy() to resolve it. It would be helpful if you could strip your application down to the smallest repro possible and uploaded it and/or built waffle and tried a couple of things (I would start by clearing WindowsAuthProviderImpl._continueContexts hash table from NegotiateSecurityFilter.destroy()).

Coordinator
Jul 22, 2010 at 11:27 AM
This discussion has been copied to a work item. Click here to go to the work item and continue the discussion.
Jul 25, 2010 at 7:57 AM

Okay, so reading your last comment in the work item, I think I will deploy the jna.jar globally and the waffle-jna.jar locally.

/lib -> platform.jar, jna.jar

/WEB-INF/lib -> waffle-jna.jar commons-logging.jar

I think, at this time, this is for me the safest way. Thanks for your help in analyzing this problem.

Coordinator
Jul 25, 2010 at 7:43 PM

I think you're doing the right thing. Thank you for bringing this up, I learned a lot about class loaders while debugging the problem :)