Bug 57173 - EOFException during annotation scanning
EOFException during annotation scanning
Status: RESOLVED FIXED
Product: Tomcat 7
Classification: Unclassified
Component: Catalina
7.0.56
PC All
: P2 normal (vote)
: ---
Assigned To: Tomcat Developers Mailing List
:
: 57260 (view as bug list)
Depends on:
Blocks:
  Show dependency tree
 
Reported: 2014-10-31 12:30 UTC by Peter
Modified: 2014-11-25 15:54 UTC (History)
2 users (show)



Attachments
complete console output (6.38 KB, text/plain)
2014-10-31 12:30 UTC, Peter
Details
woodstox JAR of my installation (443.26 KB, application/zip)
2014-11-03 07:18 UTC, Peter
Details
2014-11-08_tc8_57173_test_v1.patch (1.80 KB, patch)
2014-11-08 01:17 UTC, Konstantin Kolinko
Details | Diff
2014-11-08_tc8_57173_test_v2.patch (2.05 KB, patch)
2014-11-08 01:18 UTC, Konstantin Kolinko
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Peter 2014-10-31 12:30:26 UTC
Created attachment 32176 [details]
complete console output

After updating Tomcat from version 7.0.54 to 7.0.56 the following exception occurs during startup:
---------------------------------------
...
Okt 30, 2014 2:00:45 PM org.apache.catalina.startup.ContextConfig processAnnotationsJar
SEVERE: Unable to process Jar entry [com/ctc/wstx/api/ReaderConfig.class] from Jar [jar:jndi:/localhost/ssms-gui/WEB-INF/lib/woodstox-core-asl-4.1.2.jar!/] for annotations
java.io.EOFException
        at org.apache.tomcat.util.bcel.classfile.FastDataInputStream.readUnsignedShort(FastDataInputStream.java:120)
        at org.apache.tomcat.util.bcel.classfile.Utility.swallowFieldOrMethod(Utility.java:75)
        at org.apache.tomcat.util.bcel.classfile.ClassParser.readMethods(ClassParser.java:235)
        at org.apache.tomcat.util.bcel.classfile.ClassParser.parse(ClassParser.java:92)
        at org.apache.catalina.startup.ContextConfig.processAnnotationsStream(ContextConfig.java:2071)
        at org.apache.catalina.startup.ContextConfig.processAnnotationsJar(ContextConfig.java:1947)
        at org.apache.catalina.startup.ContextConfig.processAnnotationsUrl(ContextConfig.java:1913)
        at org.apache.catalina.startup.ContextConfig.processAnnotations(ContextConfig.java:1898)
        at org.apache.catalina.startup.ContextConfig.webConfig(ContextConfig.java:1330)
        at org.apache.catalina.startup.ContextConfig.configureStart(ContextConfig.java:889)
        at org.apache.catalina.startup.ContextConfig.lifecycleEvent(ContextConfig.java:386)
        at org.apache.catalina.util.LifecycleSupport.fireLifecycleEvent(LifecycleSupport.java:117)
        at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:90)
        at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5380)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
        at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:901)
        at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:877)
        at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:649)
        at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1083)
        at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1879)
        at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
        at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)
        at java.util.concurrent.FutureTask.run(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
...
---------------------------------------

This exception occurs for several JAR files and did not happen with tomcat 7.0.54. Complete console output attached.
Comment 1 Konstantin Kolinko 2014-11-01 11:40:41 UTC
1. Is this issue reproducible or just happened once?

2. Please verify that your copy of woodstox-core-asl-4.1.2.jar is a correct one, not truncated or otherwise tampered with.

I am unable to reproduce any issues with my copy of the library.
It has size 478 935 bytes, md5 ba7562cc58d6652e7d8e6095ad6e2940, sha1 b8df430ddc4947bc7b68af5ed09b8c1c5b527553.

(There is a testcase org.apache.tomcat.util.bcel.TesterPerformance that performs parsing of all classes in a Jar. I also tried to put the library into a web application.)

3. A library can be excluded from annotation scanning. See
https://wiki.apache.org/tomcat/HowTo/FasterStartUp
Comment 2 Konstantin Kolinko 2014-11-02 18:47:05 UTC
What is the version of Java runtime that you are using?
(So that one could actually reproduce the issue)


Thoughts:
1) FastDataInputStream.fillNew() shall check that this.in.read() is not -1.

2) FastDataInputStream.readUnsignedShort() expects that fillNew() call will read at least 2 bytes, but read() can actually return after reading 1 byte (I think it may depend on internal implementation of zip inflater thus my question on the version of Java that OP is using), so some looping is needed like in FastDataInputStream.readFully(..)/skipBytes().

There is also a question of whether FastDataInputStream with such changes remains faster than the original DataInputStream.
Comment 3 Peter 2014-11-03 07:17:16 UTC
To your questions:
> 1. Is this issue reproducible or just happened once?

It is reproducible with every startup of tomcat.


> 2. Please verify that your copy of woodstox-core-asl-4.1.2.jar is a correct one, not truncated or otherwise tampered with.
> I am unable to reproduce any issues with my copy of the library.
> It has size 478 935 bytes, md5 ba7562cc58d6652e7d8e6095ad6e2940, sha1 b8df430ddc4947bc7b68af5ed09b8c1c5b527553.
> (There is a testcase org.apache.tomcat.util.bcel.TesterPerformance that performs parsing of all classes in a Jar. I also tried to put the library into a web application.)

I double checked the file. It is the correct one. Attached you can find a copy of my JAR (zipped).


> 3. A library can be excluded from annotation scanning. See
> https://wiki.apache.org/tomcat/HowTo/FasterStartUp

Thank you, but I was aware of that. It would be OK for the "woodstox" library, but not for the "trinidad-impl-2.1.1-ks1.jar" which is also failing.


> What is the version of Java runtime that you are using?
> (So that one could actually reproduce the issue)

We are currently using a rather old JVM:
java version "1.7.0_25"
Java(TM) SE Runtime Environment (build 1.7.0_25-b17)
Java HotSpot(TM) 64-Bit Server VM (build 23.25-b01, mixed mode)

Is there any difference, if I would use a newer one?
Comment 4 Peter 2014-11-03 07:18:20 UTC
Created attachment 32181 [details]
woodstox JAR of my installation
Comment 5 Peter 2014-11-03 07:35:54 UTC
I tried with a newer JVM, but got the same exceptions:
-----
java version "1.7.0_72"
Java(TM) SE Runtime Environment (build 1.7.0_72-b14)
Java HotSpot(TM) 64-Bit Server VM (build 24.72-b04, mixed mode)
Comment 6 Violeta Georgieva 2014-11-03 18:26:50 UTC
I can reproduce the issue:


SEVERE: Unable to process Jar entry [ch/qos/logback/core/status/Status.class] from Jar [jar:jndi:/localhost/no-manifest/WEB-INF/lib/com.springsource.ch.qos.logback.core-0.9.18.jar!/] for annotations
java.io.EOFException
	at org.apache.tomcat.util.bcel.classfile.FastDataInputStream.readInt(FastDataInputStream.java:145)
	at org.apache.tomcat.util.bcel.classfile.ClassParser.readID(ClassParser.java:200)


Setup:
- tomcat 7.0.56 with default settings
- only unpackWARs is set to false

      <Host name="localhost"  appBase="webapps"
            unpackWARs="false" autoDeploy="true">


If unpackWARs is set to true there are no problems.

The problem does not appear in 7.0.55 and appear in 7.0.56 and tc7.0.x.
Comment 7 Peter 2014-11-04 07:12:23 UTC
In my installation unpackWARs is also set to false:

<Host appBase="webapps" autoDeploy="false" name="localhost" unpackWARs="false">
Comment 8 auke.poortman 2014-11-06 09:27:06 UTC
In our Tomcat-7.0.56 installation we're experiencing the same annotations-check problem. I've tried to set unpackWar to true but that doesn't seem to be the problem in our case. 
Although we're getting these exceptions our applications don't seem to have any trouble with it.
Comment 9 Konstantin Kolinko 2014-11-08 01:17:21 UTC
Created attachment 32195 [details]
2014-11-08_tc8_57173_test_v1.patch

Modification of TesterPerformance test that uses an InputStream that reads only one byte at each read() call.
Comment 10 Konstantin Kolinko 2014-11-08 01:18:36 UTC
Created attachment 32196 [details]
2014-11-08_tc8_57173_test_v2.patch

Modification of TesterPerformance test that uses an InputStream that reads a random count of bytes on each read() call. The count of bytes ranges from 1 up to requested length.
Comment 11 Konstantin Kolinko 2014-11-08 01:26:38 UTC
Steps to run the tests:
1. Apply patch (attachment 32195 [details] or attachment 32196 [details])
2. Put some jars into /tmp/jira-libs
3. Run org.apache.tomcat.util.bcel.TesterPerformance test

With patch 1 the test fails in readInt() call when reading the signature of the class file. With patch 2 the test fails randomly in some read[Int,UnsignedInt] etc. method.

Thus FastDataInputStream is broken.
Comment 12 Konstantin Kolinko 2014-11-08 02:12:09 UTC
Fixed in trunk by r1637501.
I disabled mark() method, as I see that the current implementation of fillNew() method is not compatible with it. It does not take into account the marker position.

In my test with trunk and JDK 8u25 the "FastDataInputStream" is faster by 2%. That is not much of a difference. Reverting r1625504 is an option.
Comment 13 Mark Thomas 2014-11-24 12:59:20 UTC
*** Bug 57251 has been marked as a duplicate of this bug. ***
Comment 14 Mark Thomas 2014-11-25 15:25:46 UTC
*** Bug 57260 has been marked as a duplicate of this bug. ***
Comment 15 Mark Thomas 2014-11-25 15:27:47 UTC
We are seeing lots of these regressions. I am going to revert r1625504.
Comment 16 Mark Thomas 2014-11-25 15:49:26 UTC
The performance improvement that triggered this regression has been reverted from from trunk, 8.0.x (for 8.0.16 onwards) and 7.0.x (for 7.0.58 onwards) and will not be reapplied.
Comment 17 Florian Schäfer 2014-11-25 15:54:30 UTC
Thanks for the fast response!