Re: Deploying war, Negative Date exception

2020-10-12 Thread Mark Thomas
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

2020-10-12 Thread Christopher Schultz
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

2020-10-12 Thread Peter Henderson
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

2020-10-12 Thread Mark Thomas
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

2020-10-12 Thread Mark Thomas
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

2020-10-12 Thread Martin Grigorov
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

2020-10-12 Thread Mark Thomas
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