You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Jesse Farinacci <ji...@gmail.com> on 2012/05/10 14:29:26 UTC
org.apache.coyote.http11.AbstractHttp11Processor.process Error
processing request
Greetings,
I'm running Apache Tomcat 7.0.27 on Linux 2.6.32.x kernel, where
Tomcat reports at startup:
Loaded APR based Apache Tomcat Native library 1.1.22
and Connector definitions look like:
<Connector scheme="http" address="a.b.c.d" port="8080"
compression="on" enableLookups="false" URIEncoding="UTF-8"/>
<Connector scheme="https" address="a.b.c.d" port="8443" secure="true"
compression="on" enableLookups="false" URIEncoding="UTF-8"
SSLEnabled="true"
SSLCertificateFile="${catalina.home}/conf/cacert.pem"
SSLCertificateKeyFile="${catalina.home}/conf/privkey.pem"/>
The web application was deployed via the manager application, and it
is unpacked into ROOT/ directory. On most every request we're seeing
delays and then in the log:
10-May-2012 08:13:58.523 SEVERE [AsyncFileHandlerWriter-1685021807]
org.apache.coyote.http11.AbstractHttp11Processor.process Error
processing request
java.lang.IllegalStateException: zip file closed
at java.util.jar.JarFile.getMetaInfEntryNames(Native Method)
at java.util.jar.JarFile.maybeInstantiateVerifier(JarFile.java:329)
at java.util.jar.JarFile.getInputStream(JarFile.java:433)
at org.apache.naming.resources.WARDirContext$WARResource.streamContent(WARDirContext.java:988)
at org.apache.naming.resources.ProxyDirContext.cacheLoad(ProxyDirContext.java:1656)
at org.apache.naming.resources.ProxyDirContext.cacheLookup(ProxyDirContext.java:1536)
at org.apache.naming.resources.ProxyDirContext.lookup(ProxyDirContext.java:297)
at org.apache.tomcat.util.http.mapper.Mapper.internalMapWrapper(Mapper.java:996)
at org.apache.tomcat.util.http.mapper.Mapper.internalMap(Mapper.java:808)
at org.apache.tomcat.util.http.mapper.Mapper.map(Mapper.java:671)
at org.apache.catalina.connector.CoyoteAdapter.postParseRequest(CoyoteAdapter.java:646)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:402)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:999)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:565)
at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:1770)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:898)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:920)
at java.lang.Thread.run(Thread.java:736)
This has been happening for a while, but it never really caused
delays. Now users are seeing the delays and so the issue has
escalated.. Any help is appreciated, let me know if I can provide some
better data,
-Jesse
--
There are 10 types of people in this world, those
that can read binary and those that can not.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: org.apache.coyote.http11.AbstractHttp11Processor.process Error
processing request
Posted by Konstantin Kolinko <kn...@gmail.com>.
2012/5/12 Mark Thomas <ma...@apache.org>:
> On 12/05/2012 18:01, Konstantin Kolinko wrote:
>> 2012/5/12 Jesse Farinacci <ji...@gmail.com>:
>
>>> With the listeners all added, things are working as I expect. The
>>> resource is served, no error is produced. I still think this is a bug
>>> though.. if I open a new bug, will it be accepted?
>>>
>>
>> (...)
>>
>
> Now there is a simple, reproducible test case, I'd be happy to see a bug
> opened and will add it to my list of things to do for the next Tomcat
> release.
>
> I agree removing the leak prevention listener is a bad idea but this
> particular side effect is not one I would expect. I suspect it has
> something to do with urlCacheProtection. We'll see.
>
I've filed
https://issues.apache.org/bugzilla/show_bug.cgi?id=53225
Best regards,
Konstantin Kolinko
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: org.apache.coyote.http11.AbstractHttp11Processor.process Error
processing request
Posted by Mark Thomas <ma...@apache.org>.
On 12/05/2012 18:01, Konstantin Kolinko wrote:
> 2012/5/12 Jesse Farinacci <ji...@gmail.com>:
>> With the listeners all added, things are working as I expect. The
>> resource is served, no error is produced. I still think this is a bug
>> though.. if I open a new bug, will it be accepted?
>>
>
> I do not know.
>
> If there exists a simple solution (like reopening the closed jar in
> WARDirContext?) then it is worth trying.
>
> If there is not, then I see little wrong with resolving it as WONTFIX
> and asking people to have proper configuration, but I will leave it to
> others for a while to take another look and decide.
>
> As with enhancement requests, if there is a patch, or if there is wide
> interest in it (other ways to trigger it?), the more are its chances.
>
> I personally have some grudge against WebappClassLoader.closeJARs() [2]
> and maybe disabling it will workaround the issue (not tested) but I do
> not know what actually happens here at the moment.
>
> [2] https://issues.apache.org/bugzilla/show_bug.cgi?id=52448
Now there is a simple, reproducible test case, I'd be happy to see a bug
opened and will add it to my list of things to do for the next Tomcat
release.
I agree removing the leak prevention listener is a bad idea but this
particular side effect is not one I would expect. I suspect it has
something to do with urlCacheProtection. We'll see.
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: org.apache.coyote.http11.AbstractHttp11Processor.process Error
processing request
Posted by Konstantin Kolinko <kn...@gmail.com>.
2012/5/12 Jesse Farinacci <ji...@gmail.com>:
> Greetings,
>
> On Fri, May 11, 2012 at 8:47 PM, Konstantin Kolinko
> <kn...@gmail.com> wrote:
>> I can easily reproduce this "zip file closed" issue in trunk with a
>> simple jar containing Tomcat's icon in META-INF/resources/favicon.ico
>> if I change configuration by removing JreMemoryLeakPreventionListener
>> from server.xml.
>> The first request to <appname>/favicon.ico hits the error.
>
> Thank you for reproducing the problem. I confirm that my Apache Tomcat
> instance was not running with that listener. I've now set:
>
> <Listener className="org.apache.catalina.core.AprLifecycleListener"/>
> <Listener className="org.apache.catalina.core.JasperListener"/>
> <Listener className="org.apache.catalina.core.JreMemoryLeakPreventionListener"
> />
> <Listener className="org.apache.catalina.core.ThreadLocalLeakPreventionListener"
> />
> <Listener className="org.apache.catalina.mbeans.GlobalResourcesLifecycleListener"/>
> <Listener className="org.apache.catalina.security.SecurityListener" />
>
>> It is a rare configuration and IMHO a broken one.
>> I think that running without JreMemoryLeakPreventionListener is wrong.
>
> Here I must object. Yes, it probably is rare, but running without
> those extra listeners isn't wrong.
They are there for a reason.
You would experience a number of other issues during webapp
undeploy/reload if you do not have that listener configured.
> I have a web application with a
> valid library in WEB-INF/lib which ships a specification supported
> static resource. That resource is not being served by Apache Tomcat
> unless I enable a non-standard (specification wise) option. That
> doesn't seem right to me..
>
Well, if you remove "JasperListener", you wouldn't be able to serve JSPs.
If you change conf/web.xml you may break some specification-dictated
defaults (such as the default list of welcome files, or jsp support).
If you do not explicitly set "o.a.c.STRICT_SERVLET_COMPLIANCE" system
property to the value of "true" you are not adhering to the spec
either.
There are many ways to break things.
>> I cannot reproduce the issue with the standard configuration.
>
> With the listeners all added, things are working as I expect. The
> resource is served, no error is produced. I still think this is a bug
> though.. if I open a new bug, will it be accepted?
>
I do not know.
If there exists a simple solution (like reopening the closed jar in
WARDirContext?) then it is worth trying.
If there is not, then I see little wrong with resolving it as WONTFIX
and asking people to have proper configuration, but I will leave it to
others for a while to take another look and decide.
As with enhancement requests, if there is a patch, or if there is wide
interest in it (other ways to trigger it?), the more are its chances.
I personally have some grudge against WebappClassLoader.closeJARs() [2]
and maybe disabling it will workaround the issue (not tested) but I do
not know what actually happens here at the moment.
[2] https://issues.apache.org/bugzilla/show_bug.cgi?id=52448
Best regards,
Konstantin Kolinko
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: org.apache.coyote.http11.AbstractHttp11Processor.process Error
processing request
Posted by Jesse Farinacci <ji...@gmail.com>.
Greetings,
On Fri, May 11, 2012 at 8:47 PM, Konstantin Kolinko
<kn...@gmail.com> wrote:
> I can easily reproduce this "zip file closed" issue in trunk with a
> simple jar containing Tomcat's icon in META-INF/resources/favicon.ico
> if I change configuration by removing JreMemoryLeakPreventionListener
> from server.xml.
> The first request to <appname>/favicon.ico hits the error.
Thank you for reproducing the problem. I confirm that my Apache Tomcat
instance was not running with that listener. I've now set:
<Listener className="org.apache.catalina.core.AprLifecycleListener"/>
<Listener className="org.apache.catalina.core.JasperListener"/>
<Listener className="org.apache.catalina.core.JreMemoryLeakPreventionListener"
/>
<Listener className="org.apache.catalina.core.ThreadLocalLeakPreventionListener"
/>
<Listener className="org.apache.catalina.mbeans.GlobalResourcesLifecycleListener"/>
<Listener className="org.apache.catalina.security.SecurityListener" />
> It is a rare configuration and IMHO a broken one.
> I think that running without JreMemoryLeakPreventionListener is wrong.
Here I must object. Yes, it probably is rare, but running without
those extra listeners isn't wrong. I have a web application with a
valid library in WEB-INF/lib which ships a specification supported
static resource. That resource is not being served by Apache Tomcat
unless I enable a non-standard (specification wise) option. That
doesn't seem right to me..
> I cannot reproduce the issue with the standard configuration.
With the listeners all added, things are working as I expect. The
resource is served, no error is produced. I still think this is a bug
though.. if I open a new bug, will it be accepted?
-Jesse
--
There are 10 types of people in this world, those
that can read binary and those that can not.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: org.apache.coyote.http11.AbstractHttp11Processor.process Error
processing request
Posted by Konstantin Kolinko <kn...@gmail.com>.
2012/5/10 Jesse Farinacci <ji...@gmail.com>:
> Greetings,
>
> I'm running Apache Tomcat 7.0.27 on Linux 2.6.32.x kernel, where
> Tomcat reports at startup:
>
> Loaded APR based Apache Tomcat Native library 1.1.22
>
> and Connector definitions look like:
>
> <Connector scheme="http" address="a.b.c.d" port="8080"
> compression="on" enableLookups="false" URIEncoding="UTF-8"/>
> <Connector scheme="https" address="a.b.c.d" port="8443" secure="true"
> compression="on" enableLookups="false" URIEncoding="UTF-8"
> SSLEnabled="true"
> SSLCertificateFile="${catalina.home}/conf/cacert.pem"
> SSLCertificateKeyFile="${catalina.home}/conf/privkey.pem"/>
>
> The web application was deployed via the manager application, and it
> is unpacked into ROOT/ directory. On most every request we're seeing
> delays and then in the log:
>
> 10-May-2012 08:13:58.523 SEVERE [AsyncFileHandlerWriter-1685021807]
> org.apache.coyote.http11.AbstractHttp11Processor.process Error
> processing request
> java.lang.IllegalStateException: zip file closed
> at java.util.jar.JarFile.getMetaInfEntryNames(Native Method)
> at java.util.jar.JarFile.maybeInstantiateVerifier(JarFile.java:329)
> at java.util.jar.JarFile.getInputStream(JarFile.java:433)
> at org.apache.naming.resources.WARDirContext$WARResource.streamContent(WARDirContext.java:988)
> at org.apache.naming.resources.ProxyDirContext.cacheLoad(ProxyDirContext.java:1656)
> at org.apache.naming.resources.ProxyDirContext.cacheLookup(ProxyDirContext.java:1536)
> at org.apache.naming.resources.ProxyDirContext.lookup(ProxyDirContext.java:297)
> at org.apache.tomcat.util.http.mapper.Mapper.internalMapWrapper(Mapper.java:996)
> at org.apache.tomcat.util.http.mapper.Mapper.internalMap(Mapper.java:808)
> at org.apache.tomcat.util.http.mapper.Mapper.map(Mapper.java:671)
> at org.apache.catalina.connector.CoyoteAdapter.postParseRequest(CoyoteAdapter.java:646)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:402)
> at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:999)
> at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:565)
> at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:1770)
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:898)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:920)
> at java.lang.Thread.run(Thread.java:736)
>
> This has been happening for a while, but it never really caused
> delays. Now users are seeing the delays and so the issue has
> escalated.. Any help is appreciated, let me know if I can provide some
> better data,
I can easily reproduce this "zip file closed" issue in trunk with a
simple jar containing Tomcat's icon in META-INF/resources/favicon.ico
if I change configuration by removing JreMemoryLeakPreventionListener
from server.xml.
The first request to <appname>/favicon.ico hits the error.
It is a rare configuration and IMHO a broken one.
I think that running without JreMemoryLeakPreventionListener is wrong.
A place that I know that closes JARs is WebappClassLoader#closeJARs().
The closeJARs() is called after StandardContext has started up.
But WebappClassLoader and WARDirContext use different API to locate
and open the JAR file and I do not see how they can interfere with
each other.
I cannot reproduce the issue with the standard configuration.
Best regards,
Konstantin Kolinko
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: org.apache.coyote.http11.AbstractHttp11Processor.process Error
processing request
Posted by Konstantin Kolinko <kn...@gmail.com>.
2012/5/10 Jesse Farinacci <ji...@gmail.com>:
>
> Given this insight, thank you, I don't think that this is the cause
> for delay and I will investigate outside of Apache Tomcat for the root
> cause.
>
Regarding your original issue of delays, it would be nice to get
actual thread dumps from the moment when you experience the delay.
Maybe StuckThreadDetectionValve in Tomcat 7 can help here.
Best regards,
Konstantin Kolinko
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: org.apache.coyote.http11.AbstractHttp11Processor.process Error
processing request
Posted by Jesse Farinacci <ji...@gmail.com>.
Greetings,
On Thu, May 10, 2012 at 2:37 PM, Mark Thomas <ma...@apache.org> wrote:
> I've had a good look at the code and I can't see anything that jumps out
> as the cause of this. Does this happen as soon as Tomcat starts, after a
> while, after a reload, after something else?
It happens when the browser makes a request for the favicon.ico. That
resource is contained inside
WEB-INF/lib/common-favicon.jar!/META-INF/resources/favicon.ico file.
When the resource is requested, Apache Tomcat puts that stack trace
into the log and returns a HTTP-500 return code to the browser.
-Jesse
--
There are 10 types of people in this world, those
that can read binary and those that can not.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: org.apache.coyote.http11.AbstractHttp11Processor.process Error
processing request
Posted by Mark Thomas <ma...@apache.org>.
On 10/05/2012 16:57, Jesse Farinacci wrote:
> Greetings,
>
> On Thu, May 10, 2012 at 11:41 AM, Mark Thomas <ma...@apache.org> wrote:
>> The thing that doesn't make sense yet is that Tomcat is trying to read from a WAR (or possibly a JAR) but the app should be unpacked. With that in mind:
>> - requests for what resources trigger this problem?
>> - where is that resource located in the unpacked application?
>> - are you making use of Servlet 3.0 resource JARs.
>
> Your instinct is quite good. Yes, that is exactly where the error is
> happening. I narrowed it down to our WEB-INF/lib/common-favicon.jar
> which has (among other automatically generated Maven junk):
>
> META-INF/resources/
> META-INF/resources/favicon.ico
> META-INF/resources/images/
> META-INF/resources/images/favicon.ico
>
> Legacy reasons for the duplicated paths, please ignore this
> idiosyncrasy. But, we take HTTP-500 when trying to fetch the
> favicon.ico image directly, both paths. The stack trace I reported
> before is generated each time.
>
> Given this insight, thank you, I don't think that this is the cause
> for delay and I will investigate outside of Apache Tomcat for the root
> cause.
I've had a good look at the code and I can't see anything that jumps out
as the cause of this. Does this happen as soon as Tomcat starts, after a
while, after a reload, after something else?
Cheers,
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: org.apache.coyote.http11.AbstractHttp11Processor.process Error
processing request
Posted by Jesse Farinacci <ji...@gmail.com>.
Greetings,
On Thu, May 10, 2012 at 11:41 AM, Mark Thomas <ma...@apache.org> wrote:
> The thing that doesn't make sense yet is that Tomcat is trying to read from a WAR (or possibly a JAR) but the app should be unpacked. With that in mind:
> - requests for what resources trigger this problem?
> - where is that resource located in the unpacked application?
> - are you making use of Servlet 3.0 resource JARs.
Your instinct is quite good. Yes, that is exactly where the error is
happening. I narrowed it down to our WEB-INF/lib/common-favicon.jar
which has (among other automatically generated Maven junk):
META-INF/resources/
META-INF/resources/favicon.ico
META-INF/resources/images/
META-INF/resources/images/favicon.ico
Legacy reasons for the duplicated paths, please ignore this
idiosyncrasy. But, we take HTTP-500 when trying to fetch the
favicon.ico image directly, both paths. The stack trace I reported
before is generated each time.
Given this insight, thank you, I don't think that this is the cause
for delay and I will investigate outside of Apache Tomcat for the root
cause.
-Jesse
--
There are 10 types of people in this world, those
that can read binary and those that can not.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org
Re: org.apache.coyote.http11.AbstractHttp11Processor.process Error processing request
Posted by Mark Thomas <ma...@apache.org>.
Jesse Farinacci <ji...@gmail.com> wrote:
>Greetings,
>
>I'm running Apache Tomcat 7.0.27 on Linux 2.6.32.x kernel, where
>Tomcat reports at startup:
>
> Loaded APR based Apache Tomcat Native library 1.1.22
>
>and Connector definitions look like:
>
> <Connector scheme="http" address="a.b.c.d" port="8080"
> compression="on" enableLookups="false" URIEncoding="UTF-8"/>
> <Connector scheme="https" address="a.b.c.d" port="8443" secure="true"
> compression="on" enableLookups="false" URIEncoding="UTF-8"
> SSLEnabled="true"
>SSLCertificateFile="${catalina.home}/conf/cacert.pem"
>SSLCertificateKeyFile="${catalina.home}/conf/privkey.pem"/>
>
>The web application was deployed via the manager application, and it
>is unpacked into ROOT/ directory. On most every request we're seeing
>delays and then in the log:
>
>10-May-2012 08:13:58.523 SEVERE [AsyncFileHandlerWriter-1685021807]
>org.apache.coyote.http11.AbstractHttp11Processor.process Error
>processing request
> java.lang.IllegalStateException: zip file closed
> at java.util.jar.JarFile.getMetaInfEntryNames(Native Method)
> at java.util.jar.JarFile.maybeInstantiateVerifier(JarFile.java:329)
> at java.util.jar.JarFile.getInputStream(JarFile.java:433)
>at
>org.apache.naming.resources.WARDirContext$WARResource.streamContent(WARDirContext.java:988)
>at
>org.apache.naming.resources.ProxyDirContext.cacheLoad(ProxyDirContext.java:1656)
>at
>org.apache.naming.resources.ProxyDirContext.cacheLookup(ProxyDirContext.java:1536)
>at
>org.apache.naming.resources.ProxyDirContext.lookup(ProxyDirContext.java:297)
>at
>org.apache.tomcat.util.http.mapper.Mapper.internalMapWrapper(Mapper.java:996)
>at
>org.apache.tomcat.util.http.mapper.Mapper.internalMap(Mapper.java:808)
> at org.apache.tomcat.util.http.mapper.Mapper.map(Mapper.java:671)
>at
>org.apache.catalina.connector.CoyoteAdapter.postParseRequest(CoyoteAdapter.java:646)
>at
>org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:402)
>at
>org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:999)
>at
>org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:565)
>at
>org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:1770)
>at
>java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:898)
>at
>java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:920)
> at java.lang.Thread.run(Thread.java:736)
>
>This has been happening for a while, but it never really caused
>delays. Now users are seeing the delays and so the issue has
>escalated.. Any help is appreciated, let me know if I can provide some
>better data,
I'm not sure the exception above will lead to delays. Then again, I'm not entirely sure why the above is happening yet so I may be wrong. I guess I am warning you that fixing this issue might not fix the delays and you may want to investigate those as a separate issue.
Anyway...
The thing that doesn't make sense yet is that Tomcat is trying to read from a WAR (or possibly a JAR) but the app should be unpacked. With that in mind:
- requests for what resources trigger this problem?
- where is that resource located in the unpacked application?
- are you making use of Servlet 3.0 resource JARs.
What I am trying to get to is a test case I can use to reproduce this.
Mark
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org