JNI error on upgrade from 8.14.5-shaded to 8.15.0-shaded

[nheitz]

openJDK 1.8.0_u191
Ubuntu 18.10

The following stack is thrown upon execution on a docker pull on one of my images:

ERROR [2019-01-24 12:04:11,930Z] [C= CR= SR=26edf226810ddc29 TASK= O=] [dw-28 - POST /catapult] i.d.j.e.LoggingExceptionMapper: Error handling a request: c7dcb5d7b536376b
! com.spotify.docker.client.exceptions.DockerException: java.util.concurrent.ExecutionException: com.spotify.docker.client.shaded.javax.ws.rs.ProcessingException: java.lang.UnsatisfiedLinkError: could not load FFI provider com.spotify.docker.client.shaded.jnr.ffi.provider.jffi.Provider
! at com.spotify.docker.client.DefaultDockerClient.propagate(DefaultDockerClient.java:2843)
! at com.spotify.docker.client.DefaultDockerClient.request(DefaultDockerClient.java:2707)
! at com.spotify.docker.client.DefaultDockerClient.requestAndTail(DefaultDockerClient.java:2792)
! at com.spotify.docker.client.DefaultDockerClient.pull(DefaultDockerClient.java:1341)
! at com..catapult.server.services.catapult.DockerCatapultProcessRunner.executeProcess(DockerCatapultProcessRunner.kt:122)
! at com..catapult.server.services.catapult.AbstractCatapultProcessRunner.run(AbstractCatapultProcessRunner.kt:132)
! at com..catapult.server.services.DefaultCatapultService.catapult(DefaultCatapultService.kt:335)
! at com..catapult.server.services.DefaultCatapultService.access$catapult(DefaultCatapultService.kt:63)
! at com..catapult.server.services.DefaultCatapultService$executeAdhoc$1.invokeSuspend(DefaultCatapultService.kt:115)
! at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:32)
! at kotlinx.coroutines.DispatchedTask.run(Dispatched.kt:233)
! at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.kt:116)
! at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:76)
! at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:53)
! at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source)
! at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:35)
! at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source)
! at com..catapult.server.services.DefaultCatapultService.executeAdhoc(DefaultCatapultService.kt:114)
! at com.****.catapult.server.resources.CatapultResource.catapultAdhoc(CatapultResource.kt:133)
! at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
! at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
! at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
! at java.lang.reflect.Method.invoke(Method.java:498)
! at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81)
! at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144)
! at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161)
! at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160)
! at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99)
! at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389)
! at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347)
! at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102)
! at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326)
! at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
! at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
! at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
! at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
! at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
! at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317)
! at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305)
! at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154)
! at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473)
! at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427)
! at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388)
! at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341)
! at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228)
! at io.dropwizard.jetty.NonblockingServletHolder.handle(NonblockingServletHolder.java:49)
! at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1655)
! at io.dropwizard.servlets.ThreadNameFilter.doFilter(ThreadNameFilter.java:35)
! at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
! at io.dropwizard.jersey.filter.AllowedMethodsFilter.handle(AllowedMethodsFilter.java:45)
! at io.dropwizard.jersey.filter.AllowedMethodsFilter.doFilter(AllowedMethodsFilter.java:39)
! at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
! at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:89)
! at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:121)
! at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:133)
! at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
! at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)
! at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
! at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1317)
! at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
! at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
! at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
! at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1219)
! at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
! at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
! at com.codahale.metrics.jetty9.InstrumentedHandler.handle(InstrumentedHandler.java:239)
! at io.dropwizard.jetty.RoutingHandler.handle(RoutingHandler.java:52)
! at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:56)
! at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:169)
! at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
! at org.eclipse.jetty.server.Server.handle(Server.java:531)
! at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352)
! at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
! at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281)
! at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
! at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
! at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762)
! at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680)
! at java.lang.Thread.run(Thread.java:748)
! Caused by: java.util.concurrent.ExecutionException: com.spotify.docker.client.shaded.javax.ws.rs.ProcessingException: java.lang.UnsatisfiedLinkError: could not load FFI provider com.spotify.docker.client.shaded.jnr.ffi.provider.jffi.Provider
! at jersey.repackaged.com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:299)
! at jersey.repackaged.com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:286)
! at jersey.repackaged.com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:116)
! at com.spotify.docker.client.DefaultDockerClient.request(DefaultDockerClient.java:2705)
! ... 77 common frames omitted
! Caused by: com.spotify.docker.client.shaded.javax.ws.rs.ProcessingException: java.lang.UnsatisfiedLinkError: could not load FFI provider com.spotify.docker.client.shaded.jnr.ffi.provider.jffi.Provider
! at com.spotify.docker.client.shaded.org.glassfish.jersey.client.ClientRuntime.processFailure(ClientRuntime.java:202)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.client.ClientRuntime.access$400(ClientRuntime.java:79)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.client.ClientRuntime$2.run(ClientRuntime.java:182)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.internal.Errors.process(Errors.java:315)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.internal.Errors.process(Errors.java:297)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.internal.Errors.process(Errors.java:267)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:340)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.client.ClientRuntime$3.run(ClientRuntime.java:210)
! at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
! at java.util.concurrent.FutureTask.run(FutureTask.java:266)
! at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
! at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
! ... 1 common frames omitted
! Caused by: java.lang.UnsatisfiedLinkError: could not load FFI provider com.spotify.docker.client.shaded.jnr.ffi.provider.jffi.Provider
! at com.spotify.docker.client.shaded.jnr.ffi.provider.InvalidProvider$1.loadLibrary(InvalidProvider.java:48)
! at com.spotify.docker.client.shaded.jnr.ffi.LibraryLoader.load(LibraryLoader.java:325)
! at com.spotify.docker.client.shaded.jnr.unixsocket.Native.(Native.java:80)
! at com.spotify.docker.client.shaded.jnr.unixsocket.UnixSocketChannel.(UnixSocketChannel.java:101)
! at com.spotify.docker.client.shaded.jnr.unixsocket.UnixSocketChannel.open(UnixSocketChannel.java:60)
! at com.spotify.docker.client.UnixConnectionSocketFactory.createSocket(UnixConnectionSocketFactory.java:69)
! at com.spotify.docker.client.UnixConnectionSocketFactory.createSocket(UnixConnectionSocketFactory.java:44)
! at com.spotify.docker.client.shaded.org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:118)
! at com.spotify.docker.client.shaded.org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:353)
! at com.spotify.docker.client.shaded.org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:380)
! at com.spotify.docker.client.shaded.org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
! at com.spotify.docker.client.shaded.org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
! at com.spotify.docker.client.shaded.org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
! at com.spotify.docker.client.shaded.org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
! at com.spotify.docker.client.shaded.org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
! at com.spotify.docker.client.shaded.org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:71)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.apache.connector.ApacheConnector.apply(ApacheConnector.java:435)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.apache.connector.ApacheConnector$1.run(ApacheConnector.java:491)
! at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
! at java.util.concurrent.FutureTask.run(FutureTask.java:266)
! at jersey.repackaged.com.google.common.util.concurrent.MoreExecutors$DirectExecutorService.execute(MoreExecutors.java:299)
! at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112)
! at jersey.repackaged.com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:50)
! at jersey.repackaged.com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:37)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.apache.connector.ApacheConnector.apply(ApacheConnector.java:487)
! at com.spotify.docker.client.shaded.org.glassfish.jersey.client.ClientRuntime$2.run(ClientRuntime.java:178)
! ... 12 common frames omitted
! Caused by: java.lang.ExceptionInInitializerError: null
! at com.spotify.docker.client.shaded.jnr.ffi.provider.jffi.NativeRuntime.getInstance(NativeRuntime.java:58)
! at com.spotify.docker.client.shaded.jnr.ffi.provider.jffi.Provider.(Provider.java:29)
! at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
! at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
! at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
! at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
! at java.lang.Class.newInstance(Class.java:442)
! at com.spotify.docker.client.shaded.jnr.ffi.provider.FFIProvider$SystemProviderSingletonHolder.getInstance(FFIProvider.java:68)
! at com.spotify.docker.client.shaded.jnr.ffi.provider.FFIProvider$SystemProviderSingletonHolder.(FFIProvider.java:57)
! at com.spotify.docker.client.shaded.jnr.ffi.provider.FFIProvider.getSystemProvider(FFIProvider.java:35)
! at com.spotify.docker.client.shaded.jnr.ffi.LibraryLoader.create(LibraryLoader.java:73)
! at com.spotify.docker.client.shaded.jnr.unixsocket.Native.(Native.java:76)
! ... 35 common frames omitted
! Caused by: java.lang.IllegalStateException: Can't overwrite cause with java.lang.UnsatisfiedLinkError: com.spotify.docker.client.shaded.com.kenai.jffi.Foreign.getVersion()I
! at java.lang.Throwable.initCause(Throwable.java:457)
! at com.spotify.docker.client.shaded.com.kenai.jffi.Type$Builtin.lookupTypeInfo(Type.java:252)
! at com.spotify.docker.client.shaded.com.kenai.jffi.Type$Builtin.getTypeInfo(Type.java:237)
! at com.spotify.docker.client.shaded.com.kenai.jffi.Type.resolveSize(Type.java:155)
! at com.spotify.docker.client.shaded.com.kenai.jffi.Type.size(Type.java:138)
! at com.spotify.docker.client.shaded.jnr.ffi.provider.jffi.NativeRuntime$TypeDelegate.size(NativeRuntime.java:187)
! at com.spotify.docker.client.shaded.jnr.ffi.provider.AbstractRuntime.(AbstractRuntime.java:48)
! at com.spotify.docker.client.shaded.jnr.ffi.provider.jffi.NativeRuntime.(NativeRuntime.java:66)
! at com.spotify.docker.client.shaded.jnr.ffi.provider.jffi.NativeRuntime.(NativeRuntime.java:41)
! at com.spotify.docker.client.shaded.jnr.ffi.provider.jffi.NativeRuntime$SingletonHolder.(NativeRuntime.java:62)
! ... 47 common frames omitted
! Caused by: java.lang.UnsatisfiedLinkError: com.spotify.docker.client.shaded.com.kenai.jffi.Foreign.getVersion()I
! at com.spotify.docker.client.shaded.com.kenai.jffi.Foreign.newLoadError(Foreign.java:72)
! at com.spotify.docker.client.shaded.com.kenai.jffi.Foreign.access$300(Foreign.java:42)
! at com.spotify.docker.client.shaded.com.kenai.jffi.Foreign$InValidInstanceHolder.getForeign(Foreign.java:98)
! at com.spotify.docker.client.shaded.com.kenai.jffi.Foreign.getInstance(Foreign.java:103)
! at com.spotify.docker.client.shaded.com.kenai.jffi.Type$Builtin.lookupTypeInfo(Type.java:242)
! ... 55 common frames omitted
! Caused by: java.lang.UnsatisfiedLinkError: com.spotify.docker.client.shaded.com.kenai.jffi.Foreign.getVersion()I
! at com.spotify.docker.client.shaded.com.kenai.jffi.Foreign.getVersion(Native Method)
! at com.spotify.docker.client.shaded.com.kenai.jffi.Foreign$InstanceHolder.getInstanceHolder(Foreign.java:53)
! at com.spotify.docker.client.shaded.com.kenai.jffi.Foreign$InstanceHolder.(Foreign.java:45)
! ... 57 common frames omitted

This works on 8.14.5, but now throws an UnsatisfiedLink exception on upgrade to the latest.

[DavidHaunsch]

Same for me, the improved shading that came with 8.15 obviously broke it.
(#1111)

[DavidHaunsch]

Seems that the problem is caused by native implementations in com.kenai.jffi that are not renamed:
http://icedtea.classpath.org/pipermail/thermostat/2016-August/020685.html

One problem I've stubled across is that jffi contains methods with native implementations. Thus, relocation for jffi does not work without also renaming the native counterparts.

[nheitz]

I attempted the same test again after the release of 8.15.1, which I believe contains your fix, but unfortunately with the same results.

! Caused by: java.lang.ClassNotFoundException: com.kenai.jffi.Type
! at java.net.URLClassLoader.findClass(URLClassLoader.java:382)
! at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
! at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:349)
! at java.lang.ClassLoader.loadClass(ClassLoader.java:357)

[DavidHaunsch]

The error message is different, seems something is missing.
The fix works for me.

[pdjacobs]

openJDK 1.8.0_u191
Ubuntu 18.04

I'm getting something very similar in 8.15.1; a call to docker.listImages(...) throws an ExecutionException that has this in the stack trace:

Caused by: java.util.concurrent.ExecutionException: com.spotify.docker.client.shaded.javax.ws.rs.ProcessingException: java.lang.UnsatisfiedLinkError: could not load FFI provider com.spotify.docker.client.shaded.jnr.ffi.provider.jffi.Provider
	at jersey.repackaged.com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:299)
	at jersey.repackaged.com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:286)
	at jersey.repackaged.com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:116)
	at com.spotify.docker.client.DefaultDockerClient.request(DefaultDockerClient.java:2695)
	... 20 more
Caused by: com.spotify.docker.client.shaded.javax.ws.rs.ProcessingException: java.lang.UnsatisfiedLinkError: could not load FFI provider

[nheitz]

The error message is different, seems something is missing.
The fix works for me.

I added com.github.jnr jffi package, thinking this might help, but now

! Caused by: java.lang.UnsatisfiedLinkError: java.lang.UnsatisfiedLinkError: could not locate stub library in jar file. Tried [jni/x86_64-Linux/libjffi-1.2.so, /jni/x86_64-Linux/libjffi-1.2.so]

So...is there now a native dependency for this lib that didn't exist before?

[nheitz]

Finally. It seems installing (apt-get install libjffi-jni ) finally resolved the issue. How is it that this didn't matter in previous versions?

[pdjacobs]

openJDK 1.8.0_u191
Ubuntu 18.04

Well, I'm still having this problem with 8.15.2 and 8.15.3 snapshot - same "java.lang.UnsatisfiedLinkError: could not load FFI provider" exception. If I build from Maven and comment out

          <!--<excludes>
              <exclude>com.github.jnr:jffi</exclude>
            </excludes> -->

in the pom, then everything seems to work fine.

[nheitz]

openJDK 1.8.0_u191
Ubuntu 18.04

Well, I'm still having this problem with 8.15.2 and 8.15.3 snapshot - same "java.lang.UnsatisfiedLinkError: could not load FFI provider" exception. If I build from Maven and comment out

          <!--<excludes>
              <exclude>com.github.jnr:jffi</exclude>
            </excludes> -->

in the pom, then everything seems to work fine.

Have you tried this? I reckon it is just a case of their being a new non java dependency

apt-get install libjffi-jni

[pdjacobs]

openJDK 1.8.0_u191
Ubuntu 18.04
Well, I'm still having this problem with 8.15.2 and 8.15.3 snapshot - same "java.lang.UnsatisfiedLinkError: could not load FFI provider" exception. If I build from Maven and comment out

          <!--<excludes>
              <exclude>com.github.jnr:jffi</exclude>
            </excludes> -->

in the pom, then everything seems to work fine.

Have you tried this? I reckon it is just a case of their being a new non java dependency

apt-get install libjffi-jni

Ah, yes, sorry - that should have gone into my previous report. I did first verify that I had an updated version of libjffi-jni through apt. I'll try building in a clean environment and see if I can replicate having/not having the issue with the change to the pom.xml.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.