Re: Deploying war, Negative Date exception
On 12/10/2020 18:48, Christopher Schultz wrote: > There is already a check for -1 for the last-modified time for the file > in the ZIP archive. Also for 0 for some reason (sorry, Brian Kernighan, > you can't store your first file in a ZIP file!). I've tracked that change back to this: https://bz.apache.org/bugzilla/show_bug.cgi?id=33636 I don't see why "0" is not allowed (but neither do I see not allowing it being a significant problem). > I think that any negative value should be ignored, so the expanded-file > on the disk should get "now" as its last-updated time. So just change > the comparison to: > > if(lastModified > 0) { > expandedFile.setLastModified(lastModified); > } Hmm. I do wonder about silently swallowing what is almost certainly some some of build system error (and breaking caching as per BZ 33636) when lastModified is negative. Ignoring files that return -1 (not specified) seems reasonable. I think an exception is better than silently swallowing here. Mark - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Deploying war, Negative Date exception
Mark, On 10/12/20 09:50, Mark Thomas wrote: > On 12/10/2020 13:53, Mark Thomas wrote: >> On 12/10/2020 12:49, Mark Thomas wrote: >>> On 12/10/2020 12:19, Peter Henderson wrote: Hello fellow tomcat users. My environment. Tomcat: 9.0.39 Java: openjdk 11.0.8 2020-07-14 OS: Ubuntu 18.04.5 LTS Source code [0] When deploying this war [1], by copying it into the webapps directory, I get this exception. [2] java.lang.IllegalArgumentException: Negative time I only started seeing this exception when I upgraded my projects build tool version from sbt.version=1.3.10 to sbt.version=1.4.0 Is this a tomcat bug, a build tool bug or most likely something I'm doing wrong? >>> >>> Looks like an issue with the dates of files in the WAR. >>> >>> If you look at the dates of the files in the WAR nearly all of them are >>> in the future (07 Feb 2106, 06:28). >>> >>> It looks like something is overflowing but a Java long shouldn't do that. >>> >>> Need to dig into exactly what is going on as this looks like it should >>> work - even if the WAR contains files created almost a century in the >>> future. >> >> Hmm. I see the 2106 date on the file system and with Java 8 but with >> Java 11 I see 1969-dec-31 23:00 which gives -360 which triggers the >> exception. >> >> The root cause appears to be in the JRE at this point. Whether it is in >> the JRE used to create the WAR or the JRE reading the WAR is TBD. >> >> I think I am going to have to look at the raw bytes and the zip file >> spec to figure out where the root cause is. > > That was fun. > > Per the zip spec, the last modified time on those files is: > > 1969-Dec-31 23:00:00 UTC > > i.e. 1 hour before the Epoch at 1970-Jan-01 00:00:00 UTC > > It is stored as a signed 32-bit int (F1F0) which is -3600 (zip > timestamps are in seconds since the Epoch). > > Java 8 reads this incorrectly as an unsigned int (4294963696) which, > when taken as seconds since Epoch, gives 2016-Feb-07 05:28:16 UTC. Underflow! :( > (Incidently the archiver that ships with Ubuntu appears to make the same > error) > > Java 11 reads this correctly but Java does not let you set times before > the Epoch so the exception is triggered. > > The short version is that the modification times of the files in the WAR > are being set to "1969-Dec-31 23:00:00 UTC" which Java doesn't like. > > Tomcat could handle this more gracefully but the end result will be the > same - the WAR isn't going to deploy. I'm not convinced it is worth > doing anything here. > > It looks like the fix will be somewhere in the build system used to > create the WAR. There is already a check for -1 for the last-modified time for the file in the ZIP archive. Also for 0 for some reason (sorry, Brian Kernighan, you can't store your first file in a ZIP file!). I think that any negative value should be ignored, so the expanded-file on the disk should get "now" as its last-updated time. So just change the comparison to: if(lastModified > 0) { expandedFile.setLastModified(lastModified); } -chris - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Deploying war, Negative Date exception
On Mon, 12 Oct 2020 at 14:50, Mark Thomas wrote: > On 12/10/2020 13:53, Mark Thomas wrote: > > On 12/10/2020 12:49, Mark Thomas wrote: > >> On 12/10/2020 12:19, Peter Henderson wrote: > >>> Hello fellow tomcat users. > >>> > >>> My environment. > >>> Tomcat: 9.0.39 > >>> Java: openjdk 11.0.8 2020-07-14 > >>> OS: Ubuntu 18.04.5 LTS > >>> > >>> Source code [0] > >>> > >>> When deploying this war [1], by copying it into the webapps directory, > >>> I get this exception. [2] > >>> java.lang.IllegalArgumentException: Negative time > >>> > >>> > >>> I only started seeing this exception when I upgraded my projects build > tool > >>> version > >>> from > >>> sbt.version=1.3.10 > >>> to > >>> sbt.version=1.4.0 > >>> > >>> > >>> Is this a tomcat bug, a build tool bug or most likely something I'm > doing > >>> wrong? > >> > >> Looks like an issue with the dates of files in the WAR. > >> > >> If you look at the dates of the files in the WAR nearly all of them are > >> in the future (07 Feb 2106, 06:28). > >> > >> It looks like something is overflowing but a Java long shouldn't do > that. > >> > >> Need to dig into exactly what is going on as this looks like it should > >> work - even if the WAR contains files created almost a century in the > >> future. > > > > Hmm. I see the 2106 date on the file system and with Java 8 but with > > Java 11 I see 1969-dec-31 23:00 which gives -360 which triggers the > > exception. > > > > The root cause appears to be in the JRE at this point. Whether it is in > > the JRE used to create the WAR or the JRE reading the WAR is TBD. > > > > I think I am going to have to look at the raw bytes and the zip file > > spec to figure out where the root cause is. > > That was fun. > > Per the zip spec, the last modified time on those files is: > > 1969-Dec-31 23:00:00 UTC > > i.e. 1 hour before the Epoch at 1970-Jan-01 00:00:00 UTC > > It is stored as a signed 32-bit int (F1F0) which is -3600 (zip > timestamps are in seconds since the Epoch). > > Java 8 reads this incorrectly as an unsigned int (4294963696) which, > when taken as seconds since Epoch, gives 2016-Feb-07 05:28:16 UTC. > > (Incidently the archiver that ships with Ubuntu appears to make the same > error) > > Java 11 reads this correctly but Java does not let you set times before > the Epoch so the exception is triggered. > > The short version is that the modification times of the files in the WAR > are being set to "1969-Dec-31 23:00:00 UTC" which Java doesn't like. > > Tomcat could handle this more gracefully but the end result will be the > same - the WAR isn't going to deploy. I'm not convinced it is worth > doing anything here. > > It looks like the fix will be somewhere in the build system used to > create the WAR. > Thanks for digging into this. For anyone else who runs into this. When upgrading to sbt >= 1.4.0 An environment variable needs to be set SOURCE_DATE_EPOCH [0] I suspect the bug is in [1] with the orElse(0L) start of epoch looks familiar. [0] https://reproducible-builds.org/docs/source-date-epoch/ [1] https://github.com/sbt/sbt/pull/5344/commits/1d0a41520071c2fcf694d6b68e4b5e7721f7c321 Peter. > > Mark > > - > To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org > For additional commands, e-mail: users-h...@tomcat.apache.org > > -- Peter Henderson Director Starjar Ltd. www.starjar.com 0330 088 1662
Re: Deploying war, Negative Date exception
On 12/10/2020 13:53, Mark Thomas wrote: > On 12/10/2020 12:49, Mark Thomas wrote: >> On 12/10/2020 12:19, Peter Henderson wrote: >>> Hello fellow tomcat users. >>> >>> My environment. >>> Tomcat: 9.0.39 >>> Java: openjdk 11.0.8 2020-07-14 >>> OS: Ubuntu 18.04.5 LTS >>> >>> Source code [0] >>> >>> When deploying this war [1], by copying it into the webapps directory, >>> I get this exception. [2] >>> java.lang.IllegalArgumentException: Negative time >>> >>> >>> I only started seeing this exception when I upgraded my projects build tool >>> version >>> from >>> sbt.version=1.3.10 >>> to >>> sbt.version=1.4.0 >>> >>> >>> Is this a tomcat bug, a build tool bug or most likely something I'm doing >>> wrong? >> >> Looks like an issue with the dates of files in the WAR. >> >> If you look at the dates of the files in the WAR nearly all of them are >> in the future (07 Feb 2106, 06:28). >> >> It looks like something is overflowing but a Java long shouldn't do that. >> >> Need to dig into exactly what is going on as this looks like it should >> work - even if the WAR contains files created almost a century in the >> future. > > Hmm. I see the 2106 date on the file system and with Java 8 but with > Java 11 I see 1969-dec-31 23:00 which gives -360 which triggers the > exception. > > The root cause appears to be in the JRE at this point. Whether it is in > the JRE used to create the WAR or the JRE reading the WAR is TBD. > > I think I am going to have to look at the raw bytes and the zip file > spec to figure out where the root cause is. That was fun. Per the zip spec, the last modified time on those files is: 1969-Dec-31 23:00:00 UTC i.e. 1 hour before the Epoch at 1970-Jan-01 00:00:00 UTC It is stored as a signed 32-bit int (F1F0) which is -3600 (zip timestamps are in seconds since the Epoch). Java 8 reads this incorrectly as an unsigned int (4294963696) which, when taken as seconds since Epoch, gives 2016-Feb-07 05:28:16 UTC. (Incidently the archiver that ships with Ubuntu appears to make the same error) Java 11 reads this correctly but Java does not let you set times before the Epoch so the exception is triggered. The short version is that the modification times of the files in the WAR are being set to "1969-Dec-31 23:00:00 UTC" which Java doesn't like. Tomcat could handle this more gracefully but the end result will be the same - the WAR isn't going to deploy. I'm not convinced it is worth doing anything here. It looks like the fix will be somewhere in the build system used to create the WAR. Mark - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Deploying war, Negative Date exception
On 12/10/2020 12:49, Mark Thomas wrote: > On 12/10/2020 12:19, Peter Henderson wrote: >> Hello fellow tomcat users. >> >> My environment. >> Tomcat: 9.0.39 >> Java: openjdk 11.0.8 2020-07-14 >> OS: Ubuntu 18.04.5 LTS >> >> Source code [0] >> >> When deploying this war [1], by copying it into the webapps directory, >> I get this exception. [2] >> java.lang.IllegalArgumentException: Negative time >> >> >> I only started seeing this exception when I upgraded my projects build tool >> version >> from >> sbt.version=1.3.10 >> to >> sbt.version=1.4.0 >> >> >> Is this a tomcat bug, a build tool bug or most likely something I'm doing >> wrong? > > Looks like an issue with the dates of files in the WAR. > > If you look at the dates of the files in the WAR nearly all of them are > in the future (07 Feb 2106, 06:28). > > It looks like something is overflowing but a Java long shouldn't do that. > > Need to dig into exactly what is going on as this looks like it should > work - even if the WAR contains files created almost a century in the > future. Hmm. I see the 2106 date on the file system and with Java 8 but with Java 11 I see 1969-dec-31 23:00 which gives -360 which triggers the exception. The root cause appears to be in the JRE at this point. Whether it is in the JRE used to create the WAR or the JRE reading the WAR is TBD. I think I am going to have to look at the raw bytes and the zip file spec to figure out where the root cause is. Mark = - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
Re: Deploying war, Negative Date exception
Hi Peter, On Mon, Oct 12, 2020 at 2:20 PM Peter Henderson wrote: > Hello fellow tomcat users. > > My environment. > Tomcat: 9.0.39 > Java: openjdk 11.0.8 2020-07-14 > OS: Ubuntu 18.04.5 LTS > > Source code [0] > > When deploying this war [1], by copying it into the webapps directory, > I get this exception. [2] > java.lang.IllegalArgumentException: Negative time > > > I only started seeing this exception when I upgraded my projects build tool > version > from > sbt.version=1.3.10 > to > sbt.version=1.4.0 > > > Is this a tomcat bug, a build tool bug or most likely something I'm doing > wrong? > > Thanks > Peter. > > > [0] > https://github.com/bollinger/NegativeDate > > [1] > https://github.com/bollinger/NegativeDate/blob/master/Negative.war > > [2] > 2020-10-12 11:41:35.932 SEVERE oacs.HostConfig Error deploying web > application archive [/home/peter/apache-tomcat-9.0.39/webapps/Negative.war] > java.lang.IllegalStateException: Error starting child > at > > org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:720) > at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:690) > at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:706) > at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:978) > at > org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1848) > at > > java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) > at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) > at > > org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75) > at > > java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:118) > at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:773) > at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:427) > at org.apache.catalina.startup.HostConfig.check(HostConfig.java:1620) > at > org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:305) > at > > org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123) > at > > org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1151) > at > > org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1353) > at > > org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1357) > at > > org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1335) > at > > java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) > at > java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) > at > > java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) > at > > java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) > at > > java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) > at > > org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) > at java.base/java.lang.Thread.run(Thread.java:834) > Caused by: org.apache.catalina.LifecycleException: Failed to start > component > > [StandardEngine[Catalina].StandardHost[localhost].StandardContext[/Negative]] > at > > org.apache.catalina.util.LifecycleBase.handleSubClassException(LifecycleBase.java:440) > at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:198) > at > > org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:717) > ... 24 more > Caused by: java.lang.IllegalArgumentException: Negative time > at java.base/java.io.File.setLastModified(File.java:1441) > The negative time comes from jarEntry.getTime() - https://github.com/apache/tomcat/blob/d6e5d838a9565c0c4bfeca4396e6266d21a80288/java/org/apache/catalina/startup/ExpandWar.java#L167 I guess SBT creates the JAR/WAR so most probably SBT 1.4.0 is to blame here. Martin > at org.apache.catalina.startup.ExpandWar.expand(ExpandWar.java:169) > at > > org.apache.catalina.startup.ContextConfig.fixDocBase(ContextConfig.java:820) > at > > org.apache.catalina.startup.ContextConfig.beforeStart(ContextConfig.java:958) > at > > org.apache.catalina.startup.ContextConfig.lifecycleEvent(ContextConfig.java:305) > at > > org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123) > at > > org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423) > at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:182) > ... 25 more > > -- > Peter Henderson >
Re: Deploying war, Negative Date exception
On 12/10/2020 12:19, Peter Henderson wrote: > Hello fellow tomcat users. > > My environment. > Tomcat: 9.0.39 > Java: openjdk 11.0.8 2020-07-14 > OS: Ubuntu 18.04.5 LTS > > Source code [0] > > When deploying this war [1], by copying it into the webapps directory, > I get this exception. [2] > java.lang.IllegalArgumentException: Negative time > > > I only started seeing this exception when I upgraded my projects build tool > version > from > sbt.version=1.3.10 > to > sbt.version=1.4.0 > > > Is this a tomcat bug, a build tool bug or most likely something I'm doing > wrong? Looks like an issue with the dates of files in the WAR. If you look at the dates of the files in the WAR nearly all of them are in the future (07 Feb 2106, 06:28). It looks like something is overflowing but a Java long shouldn't do that. Need to dig into exactly what is going on as this looks like it should work - even if the WAR contains files created almost a century in the future. Mark > > Thanks > Peter. > > > [0] > https://github.com/bollinger/NegativeDate > > [1] > https://github.com/bollinger/NegativeDate/blob/master/Negative.war > > [2] > 2020-10-12 11:41:35.932 SEVERE oacs.HostConfig Error deploying web > application archive [/home/peter/apache-tomcat-9.0.39/webapps/Negative.war] > java.lang.IllegalStateException: Error starting child > at > org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:720) > at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:690) > at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:706) > at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:978) > at > org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1848) > at > java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) > at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) > at > org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75) > at > java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:118) > at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:773) > at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:427) > at org.apache.catalina.startup.HostConfig.check(HostConfig.java:1620) > at > org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:305) > at > org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123) > at > org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1151) > at > org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1353) > at > org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1357) > at > org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1335) > at > java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) > at > java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) > at > java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) > at > java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) > at > java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) > at > org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) > at java.base/java.lang.Thread.run(Thread.java:834) > Caused by: org.apache.catalina.LifecycleException: Failed to start > component > [StandardEngine[Catalina].StandardHost[localhost].StandardContext[/Negative]] > at > org.apache.catalina.util.LifecycleBase.handleSubClassException(LifecycleBase.java:440) > at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:198) > at > org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:717) > ... 24 more > Caused by: java.lang.IllegalArgumentException: Negative time > at java.base/java.io.File.setLastModified(File.java:1441) > at org.apache.catalina.startup.ExpandWar.expand(ExpandWar.java:169) > at > org.apache.catalina.startup.ContextConfig.fixDocBase(ContextConfig.java:820) > at > org.apache.catalina.startup.ContextConfig.beforeStart(ContextConfig.java:958) > at > org.apache.catalina.startup.ContextConfig.lifecycleEvent(ContextConfig.java:305) > at > org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123) > at > org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423) > at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:182) > ... 25 more > - To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org