Spring-boot: Auto-reloading .jar fails

Created on 16 Jun 2014 · 27Comments · Source: spring-projects/spring-boot

Looks like the .jar file auto-reloads which was kind of surprising to me, especially since it doesn't seem to be handled very well - ugly zip-related exception in the log.

Steps to reproduce:

Create a Maven project (Jar) with only "Web" style ticked on http://start.spring.io
Unpack, do an mvn package, go to target/ and run: java -jar demo-0.0.1-SNAPSHOT.jar
Project works and runs on localhost:8080 _(by "works" I mean that it serves the error 404, but that's not the point here)_
With project still running directly from target/ do an mvn package again - the original .jar file will get overwritten
Prod localhost:8080 again: you'll get a stacktrace in the log:

Exception in thread "http-nio-8080-exec-10" java.lang.NoClassDefFoundError: ch/qos/logback/classic/spi/ThrowableProxy
    at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:121)
    at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:440)
    at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)
    at ch.qos.logback.classic.Logger.log(Logger.java:788)
    at org.slf4j.bridge.SLF4JBridgeHandler.callLocationAwareLogger(SLF4JBridgeHandler.java:224)
    at org.slf4j.bridge.SLF4JBridgeHandler.publish(SLF4JBridgeHandler.java:301)
    at java.util.logging.Logger.log(Logger.java:616)
    at java.util.logging.Logger.doLog(Logger.java:641)
    at java.util.logging.Logger.logp(Logger.java:841)
    at org.apache.juli.logging.DirectJDKLog.log(DirectJDKLog.java:185)
    at org.apache.juli.logging.DirectJDKLog.error(DirectJDKLog.java:151)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1771)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1679)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:744)
Exception in thread "ContainerBackgroundProcessor[StandardEngine[Tomcat].StandardHost[localhost].StandardContext[]]" java.lang.NoClassDefFoundError: org/apache/tomcat/util/ExceptionUtils
    at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1532)
    at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1540)
    at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1519)
    at java.lang.Thread.run(Thread.java:744)
Caused by: java.lang.ClassNotFoundException: org.apache.tomcat.util.ExceptionUtils
    at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:355)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader.findClass(URLClassLoader.java:354)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:425)
    at org.springframework.boot.loader.LaunchedURLClassLoader.doLoadClass(LaunchedURLClassLoader.java:161)
    at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:131)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:358)
    ... 4 more
Caused by: java.io.EOFException: Unexpected end of ZLIB input stream
    at java.util.zip.InflaterInputStream.fill(InflaterInputStream.java:240)
    at org.springframework.boot.loader.jar.ZipInflaterInputStream.fill(ZipInflaterInputStream.java:62)
    at java.util.zip.InflaterInputStream.read(InflaterInputStream.java:158)
    at org.springframework.boot.loader.jar.ZipInflaterInputStream.read(ZipInflaterInputStream.java:52)
    at sun.misc.Resource.getBytes(Resource.java:124)
    at java.net.URLClassLoader.defineClass(URLClassLoader.java:444)
    at java.net.URLClassLoader.access$100(URLClassLoader.java:71)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:361)
    ... 11 more

In my applicatiton this makes the application stop responding, but this simplified example still happily serves the 404 - hopefully you won't need an example app that shows it. The stack trace is also slightly different:

Exception in thread "http-nio-8080-Acceptor-0" java.lang.NoClassDefFoundError: org/apache/tomcat/util/ExceptionUtils
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:840)
    at java.lang.Thread.run(Thread.java:744)
Caused by: java.lang.ClassNotFoundException: org.apache.tomcat.util.ExceptionUtils
    at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:355)
    at java.security.AccessController.doPrivileged(Native Method)
    at java.net.URLClassLoader.findClass(URLClassLoader.java:354)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:425)
    at org.springframework.boot.loader.LaunchedURLClassLoader.doLoadClass(LaunchedURLClassLoader.java:161)
    at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:131)
    at java.lang.ClassLoader.loadClass(ClassLoader.java:358)
    ... 2 more
Caused by: java.util.zip.ZipException: invalid distance too far back
    at java.util.zip.InflaterInputStream.read(InflaterInputStream.java:164)
    at org.springframework.boot.loader.jar.ZipInflaterInputStream.read(ZipInflaterInputStream.java:52)
    at sun.misc.Resource.getBytes(Resource.java:124)
    at java.net.URLClassLoader.defineClass(URLClassLoader.java:444)
    at java.net.URLClassLoader.access$100(URLClassLoader.java:71)
    at java.net.URLClassLoader$1.run(URLClassLoader.java:361)
    ... 9 more

Example app also fails with Jetty, the stacktrace doesn't mention zip though:

Exception in thread "qtp2113070601-15" java.lang.NoClassDefFoundError: ch/qos/logback/classic/spi/ThrowableProxy
    at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:121)
    at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:440)
    at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)
    at ch.qos.logback.classic.Logger.log(Logger.java:788)
    at org.eclipse.jetty.util.log.JettyAwareLogger.log(JettyAwareLogger.java:607)
    at org.eclipse.jetty.util.log.JettyAwareLogger.warn(JettyAwareLogger.java:431)
    at org.eclipse.jetty.util.log.Slf4jLog.warn(Slf4jLog.java:69)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:726)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:53)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
    at java.lang.Thread.run(Thread.java:744)
Exception in thread "qtp2113070601-16" java.lang.NoClassDefFoundError: ch/qos/logback/classic/spi/ThrowableProxy
    at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:121)
    at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:440)
    at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)
    at ch.qos.logback.classic.Logger.log(Logger.java:788)
    at org.eclipse.jetty.util.log.JettyAwareLogger.log(JettyAwareLogger.java:607)
    at org.eclipse.jetty.util.log.JettyAwareLogger.warn(JettyAwareLogger.java:431)
    at org.eclipse.jetty.util.log.Slf4jLog.warn(Slf4jLog.java:69)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:726)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:53)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
    at java.lang.Thread.run(Thread.java:744)

duplicate

Source

kryger

👍4

Most helpful comment

The exception is most probably caused by the ground moving underneath the feet of the fat jar support. We have a somewhat unique implementation where we scan the contents of the nested JARs and work out where within the actual file the contents of an entry begins.

When you read a file or class from a nested JAR we actually seek to the relevant position in the file and read the contents. This allows us to have fat jars that look nice (i.e. all the classes from the nested aren't repackaged) and that don't need to unpack things to temporary directories.

When the jar is repackaged, the positions of the nested jars changes but the previously calculated index is not updated. Hence the ZLIB input stream exceptions.

One option would be for us to check the timestamp and size of the JAR whenever an entry is read to see if we need to reindex. I'm not too keen to add this additional logic, especially as most users seem to be running using springBoot:run during development time.

philwebb on 16 Jun 2014

👍2

All 27 comments

I wouldn't expect this to work really, and it doesn't seem like you did either. Is it a feature request?

dsyer on 16 Jun 2014

Ah, forgot to add the actual question: is there a way to disable this reloading behaviour or is it something that java -jar just does and it's out of Boot's control? Not reloading would make the deployment script a bit easier to set up in Jenkins as there would be no need to stop the app before scp-ing.

kryger on 16 Jun 2014

Good question. I doubt there's much we can do. Did you try running a simple (non-Boot launched) jar and see if that would ever work? Also interesting to know would be if it works with a Boot jar that isn't a webapp I guess. Switching it off might be possible if it is an artifact of the Boot classloader (hence the answers to the questions above might be interesting).

dsyer on 16 Jun 2014

I tried Dropwizard's example app and it doesn't seem to even attempt to reload the .jar file, it serves the old contents after the file is overwritten. This suggests it's something that Boot does explicitly, right?

I could try with a non-web Boot app, but I've already used up all my investigation time for this issue for today, will do this later this week as it's not a stopper for me (...yet!). Thanks for quick reaction.

kryger on 16 Jun 2014

When the jar is repackaged, the positions of the nested jars changes but the previously calculated index is not updated. Hence the ZLIB input stream exceptions.

philwebb on 16 Jun 2014

👍2

Is it possible to put a write lock on the jar while the app is running?
Does the Spring Boot plugin rewrite the file in place? If so, it shouldn't, it could delete and recreate the jar; on Windows, it will fail if Boot's classloader keeps the file open (as it should), on Linux, the classloader will simply continue serving from the old, deleted file.

toolforger on 17 Jun 2014

Was this issue resolve? Last February, 2014 I attemted to used the maven jar plugin but did not work. Just today, I am thinking I can employ this again in our application because this feature is really neat. Unfortunately, I get same error I had a year ago.

java.lang.NoClassDefFoundError: ch/qos/logback/classic/spi/ThrowableProxy

sincang on 19 Jun 2015

I think you can probably see that the issue is still open. I don't really know what you mean by "this feature" though. What did you do and what happened and what did you think might happen?

dsyer on 19 Jun 2015

I meant the jarlauncher is really neat because makes our application deployment into production simpler. BTW, the only thing that I observed is the one jar is deplyed in a network folder. After the application been running for several minutes, the error above comes out.

sincang on 20 Jun 2015

I have not tried yet to deploy it in a local folder. I will try later and see if the error will still come out.

sincang on 20 Jun 2015

BTW, the only thing that I observed is the one jar is deplyed in a network folder. After the application been running for several minutes, the error above comes out.

If you're not replacing the jar while the application is running, you're
having a different issue.
Sounds like the jar is on a different machine than where the application
is running. This kind of scenario has been notorious for causing
problems, so the usual "best practice" advice is: Don't do that, keep
the jars locally on the machine where it's supposed to run.

toolforger on 20 Jun 2015

I have had issues on Amazon Linux where spring boot seemingly sporadically tries to re-load the jar and subsequently fails. I haven't been able to figure out what is triggering the re-loads, the mtime of the jar and temp folders seemed unchanged. Perhaps files are touched by some sort of scanner in a way which isn't immediately obvious. Anyway, for these cases it would be great to be able to disable the auto-reloading with a flag.

atorstling on 18 Nov 2015

Which case is responsible for reloading of the JAR on the fly? My application which is based on spring-boot 1.2.3 had been working fine for a couple of days when this exception was thrown, suddenly.

Exception in thread "Application-Executor-24" java.lang.NoClassDefFoundError: ch/qos/logback/classic/spi/ThrowableProxy
        at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:121)
        at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:440)
        at ch.qos.logback.classic.Logger.filterAndLog_2(Logger.java:433)
        at ch.qos.logback.classic.Logger.error(Logger.java:551)
...
Caused by: java.lang.ClassNotFoundException: ch.qos.logback.classic.spi.ThrowableProxy
        at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
        at org.springframework.boot.loader.LaunchedURLClassLoader.doLoadClass(LaunchedURLClassLoader.java:170)
        at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:136)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
        ... 31 more

My observations:

I didn't replace the JAR.
I didn't repackaged the JAR since it was created with maven.
The application had been logging something many times for a couple of days. It wasn't the first using of logback error(...) method.
I started this application at virtual machine environment (VMVare). I have never seen this exception on my physical server.

MarcinMiotk on 23 Feb 2016

Reminds me of #4968

snicoll on 23 Feb 2016

Network storage again?

dsyer on 23 Feb 2016

I'm having a very similiar issue to that described by @MarcinMiotk. We have a spring-boot (1.3.0.RELEASE) worker running on production, which collapses randomly, after having run for many hours (sometimes even days), without any trouble. The application is deployed on a virtual machine, started with java -jar and the jar is not - in any way - replaced or altered, while the application is running.

At some point, various application threads start to throw:

Exception in thread "pastillGenerationTaskExecutor-1" java.lang.NoClassDefFoundError: ch/qos/logback/classic/spi/ThrowableProxy
        at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:121)
        at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:440)
        at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)
        at ch.qos.logback.classic.Logger.error(Logger.java:555)
        at pl.dreamlab.bigdata.clickpastiller.aggregation.pastills.FileBasedPastillsFactory.createFileForPastill(FileBasedPastillsFactory.java:70)
        at pl.dreamlab.bigdata.clickpastiller.aggregation.pastills.FileBasedPastillsFactory.create(FileBasedPastillsFactory.java:47)
        at pl.dreamlab.bigdata.clickpastiller.aggregation.PastillGeneratingWorker.initializePastillIFNoneActive(PastillGeneratingWorker.java:62)
        at pl.dreamlab.bigdata.clickpastiller.aggregation.PastillGeneratingWorker.run(PastillGeneratingWorker.java:46)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.ClassNotFoundException: ch.qos.logback.classic.spi.ThrowableProxy
        at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
        at java.net.URLClassLoader$1.run(URLClassLoader.java:355)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.net.URLClassLoader.findClass(URLClassLoader.java:354)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:425)
        at org.springframework.boot.loader.LaunchedURLClassLoader.doLoadClass(LaunchedURLClassLoader.java:166)
        at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:130)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:358)
        ... 11 more

and the worker dies eventually. This seems like a very serious issue.

@dsyer @snicoll @atorstling @toolforger @philwebb Do you see any fix or a possible workaround? Since, we are deploying it onto a virtual machine (managed via proxmox), there isn't really any "local storage" available to us.

turu on 6 Mar 2016

I did some digging into the root cause of this particular exception. It happened, when a call to File.createNewFile() threw an IOException (most probably due to a temporary network issue). The IOException was then about to be handled by (among other things) calling org.slf4j.Logger.error(). That call caused the above exception.

turu on 6 Mar 2016

@turu The same temporary network issue is likely to also be the cause of ThrowableProxy failing to load. This doesn't really have anything to do with Spring Boot. You really need to fix the underlying network issue to fix this problem.

You may be able to work around the problem by aggressively loading classes when the application first starts. This will cache them in memory making your application less vulnerable to temporary network problems that make the file system inaccessible.

wilkinsona on 6 Mar 2016

I just started seeing this running locally after running for awhile. I have a couple IntelliJ windows running spring boot apps as WARs in non-embedded tomcat. Everything is fine then one app or the other starts failing with this.

wgorder on 20 Mar 2016

seeing the same thing in a grails 3.1.6 app on a 12" macbook pro and jenkins but not on a 15" using gradle 2.13 seems awfully suspicious

davydotcom on 18 May 2016

its almost as if something packaging the war file is not properly flushing it before closing

davydotcom on 18 May 2016

We started seeing this
(java.lang.NoClassDefFoundError: ch/qos/logback/classic/spi/ThrowableProxy)
exception in our spring boot app because we found that our app was not closing the file handles after opening them for reading.

Sometimes but not always the error would be proceeded by