Hi,
I'm not familiar enough with the thredds or ncWMS code to be of help
there. But I just made another test which might be of help:
I tried thredds4.1.3 on jetty 6.1.22. Here, the exception is thrown
directly during the client-abort. And it doesn't seem to be forwarded to
GetCapabilities.
Exception from the jetty log when aborting a GetMap request ( GET
'http://localhost:8080/thredds/wms/testAll/2004050412_eta_211.nc?REQUEST=GetMap&LAYERS=Z_sfc&PALETTE=redblue&SERVICE=WMS&FORMAT=image/png&VERSION=1.3.0&CRS=EPSG:4326&BBOX=-130,30,20,90&WIDTH=400&HEIGHT=400&STYLES=BOXFILL/ncview'
> /dev/null ) :
2010-03-18 10:53:21.207:WARN::Committed before 500 null
2010-03-18 10:53:21.208:WARN::/thredds/wms/testAll/2004050412_eta_211.nc
java.lang.IllegalStateException: Committed
at org.mortbay.jetty.Response.resetBuffer(Response.java:1024)
at org.mortbay.jetty.Response.sendError(Response.java:240)
at org.mortbay.jetty.Response.sendError(Response.java:342)
at
thredds.server.wms.WMSController.handleRequestInternal(WMSController.java:304)
at
org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:153)
at
org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48)
at
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:875)
at
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:809)
at
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:571)
at
org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:501)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
at
org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
at
thredds.servlet.filter.RequestPathFilter.doFilter(RequestPathFilter.java:105)
at
org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at
org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
at
org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at
org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
at
org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
at
org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
at
org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
at
org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at
org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at
org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:547)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at
org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at
org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
Jetty was freshly started, I made only one request to the jetty. I
aborted the request before it was finished.
Best regards,
Heiko
On 2010-03-18 06:46, Ethan Davis wrote:
> Hi again,
>
> OK, I can reproduce the problem reliably. It wasn't very reliable when I
> was doing it by hand. Now I'm running a script that continually makes
> GetCapabilities requests one after the other. While that script is
> running I make GetMap requests and abort them with a ctrl-C. I also have
> Tomcat configured to just 3 threads. (Thanks Heiko for figuring all that
> out! Works like a charm.)
>
> I'm catching the GetCapabilities request that is going to fail with a
> conditional breakpoint ("response.isCommitted() == true") at the
> beginning of the WMSController.handleRequestInternal() method. As we
> might expect, it looks like the response is committed from the time the
> org.apache.coyote.http11.Http11Processor creates the request and
> response objects.
>
> I haven't figured out how to reliably catch the problem during the abort
> of the GetMap request. Seems like a Tomcat issue rather than a TDS/WMS
> issue. I would think Tomcat should handle things even if we are dealing
> with an exception poorly.
>
> I'll dig around a bit more tomorrow. See if I can figure out why the
> response doesn't get reset properly.
>
> Ethan
>
>
> On 3/17/2010 11:03 AM, Ethan Davis wrote:
>> Hi Jon, Heiko,
>>
>> Jon, forgot to mention, we have code in the TDS WMS controller for
>> catching SocketException-s and ClientAbortException/IOException-s
>> similar to the change you reference.
>>
>> Have either of you seen this with ncWMS? Or is it so far just showing up
>> in TDS?
>>
>> Most of the references to this exception that I've found deal with
>> exceptions interrupting JSP processing and causing a switch to a JSP
>> error page that then can't create a session object. Since the problem
>> happens in one of our main JSP pages (capabilities_xml.jsp) and the
>> ClientAbortException-s are happening in a different thread, I'm leaning
>> towards the "thread in an invalid state" idea as well.
>>
>> One thing we could try is to set our JSP pages to not create session
>> objects: "<%@ page session='false' ...%>". But since we don't know
>> if/how the threads might be invalid, I'm afraid that would just make
>> this problem even harder to see.
>>
>> I'm going to try for a bit to get things setup so I can debug into
>> Tomcat code and see if I can catch this in action.
>>
>> Ethan
>>
>> On 3/17/2010 1:24 AM, Ethan Davis wrote:
>>> Hi Jon, Heiko,
>>>
>>> I'm having a hard time reproducing the problem reliably. I've only seen
>>> it twice so far. And haven't been able to catch it in action. I did get
>>> the IllegalStateException from the Jasper JspFactoryImpl both times:
>>>
>>> "java.lang.IllegalStateException: Cannot create a session
>>> after the response has been committed"
>>>
>>> Googling on the above exception message brings up a fair number of hits
>>> but none of them seem totally relevant. Or when they sound somewhat
>>> relevant, there isn't a solution.
>>>
>>> More tomorrow.
>>>
>>> Ethan
>>>
>>> On 3/16/2010 9:05 AM, Jonathan Blower wrote:
>>>> Hi Heiko, Ethan,
>>>>
>>>> I've been trying to figure out what might be going on here - thanks for
>>>> your great diagnosis Heiko. I'm not sure what can be done in the
>>>> THREDDS/WMS code to prevent this, but I've modified some code in the
>>>> ncWMS WmsController class to attempt to catch exceptions that are thrown
>>>> when clients disconnect:
>>>>
>>>> http://www.resc.rdg.ac.uk/trac/ncWMS/browser/branches/tds-refactor-2010-
>>>> 01-09/src/java/uk/ac/rdg/resc/ncwms/controller/WmsController.java#L250
>>>>
>>>> Heiko - you mentioned that it's possible that poor exception handling
>>>> could cause a tomcat thread to be left in an invalid state. I can't
>>>> reproduce your problem reliably so I can't test this myself, but I
>>>> wonder if you could find out whether this is happening in your setup?
>>>> The VisualVM tool
>>>> (http://java.sun.com/javase/6/docs/technotes/guides/visualvm/) can give
>>>> a thread dump from your running Tomcat system - perhaps you could run
>>>> this when an error occurs and see if anything is suspicious?
>>>>
>>>> Ethan - are you able to reproduce Heiko's problem?
>>>>
>>>> Cheers, Jon
>>>>
>>>>
>>>> -----Original Message-----
>>>> From: Ethan Davis [mailto:edavis@xxxxxxxxxxxxxxxx]
>>>> Sent: 05 March 2010 23:32
>>>> To: Heiko Klein
>>>> Cc: Jonathan Blower; thredds@xxxxxxxxxxxxxxxx
>>>> Subject: Re: [thredds] ncWMS GetCapabilities return sometimes empty
>>>> document
>>>>
>>>> Hi Heiko,
>>>>
>>>> That is great. Thanks.
>>>>
>>>> I'm a bit swamped through next week but I will jump on this the
>>>> following week before I get to some other WMS work.
>>>>
>>>> Thanks,
>>>>
>>>> Ethan
>>>>
>>>> On 3/5/2010 4:44 AM, Heiko Klein wrote:
>>>>> Hi,
>>>>>
>>>>> finally, I managed to generate a simple case how to reproduce this
>>>> error:
>>>>>
>>>>> a) start tomcat
>>>>> b) abort fetching some maps (3-4 times on a tomcat with
>>>>> 10thredds/HTTP1.1 connector), i.e. call
>>>>> GET
>>>>>
>>>> 'http://localhost:8081/thredds/wms/data/met.no/hirlam12/wam_nsea.fc.2009
>>>> 0604.nc?REQUEST=GetMap&LAYERS=significant_wave_height&PALETTE=redblue&SE
>>>> RVICE=WMS&FORMAT=image/png&VERSION=1.3.0&CRS=EPSG:4326&BBOX=-30,-60,30,9
>>>> 0&WIDTH=400&HEIGHT=400&STYLES=BOXFILL/ncview'
>>>>>> /dev/null
>>>>> and abort this call before it is finished. (Ctrl-C)
>>>>> c) get some 'getCapabilities' documents:
>>>>> while [ 1 ]; do GET
>>>>>
>>>> 'http://localhost:8081/thredds/wms/data/met.no/hirlam12/wam_nsea.fc.2009
>>>> 0604.nc?service=WMS&version=1.3.0&request=GetCapabilities'
>>>>>> testCap.xml; ls -l testCap.xml; done
>>>>> ...
>>>>> -rw-r--r-- 1 heikok heikok 172126 2010-03-05 12:11 testCap.xml
>>>>> -rw-r--r-- 1 heikok heikok 172126 2010-03-05 12:11 testCap.xml
>>>>> -rw-r--r-- 1 heikok heikok 172126 2010-03-05 12:11 testCap.xml
>>>>> -rw-r--r-- 1 heikok heikok 0 2010-03-05 12:11 testCap.xml
>>>>> -rw-r--r-- 1 heikok heikok 172126 2010-03-05 12:11 testCap.xml
>>>>> -rw-r--r-- 1 heikok heikok 172126 2010-03-05 12:11 testCap.xml
>>>>>
>>>>>
>>>>> When the capabilites document with 0 byte size is fetched, the earlier
>>>>> mentioned exception is thrown.
>>>>>
>>>>>
>>>>> Since step b) is the crucial step to reproduce the 0 byte document, I
>>>>> guess there is somewhere a badly caught
>>>> ClientAbortException/IOException
>>>>> when writing to the responses OutputStream, leaving a tomcat-thread in
>>>>> an invalid state.
>>>>>
>>>>>
>>>>> We can solve this problem currently by adding a proxy in front of
>>>>> thredds (apache mod_proxy) which seems to swallow all
>>>>> client-connection-aborts before they reach tomcat.
>>>>>
>>>>> Best regards,
>>>>>
>>>>> Heiko
>>>>>
>>>>> On 2010-02-19 16:54, Heiko Klein wrote:
>>>>>> Hi,
>>>>>>
>>>>>> I'm still trying to track down this problem, so here a short update:
>>>>>>
>>>>>> The ncWMS/TDS crashes seems to be connected to concurrency: The
>>>> problem
>>>>>> occurs when reloading the wms-client (openlayers in firefox), that
>>>> means
>>>>>> GetCapabilites and GetMap are run in parallel. We're downloading
>>>> tiles,
>>>>>> so reloading will fetch one capability doc + approx 12 maps.
>>>>>>
>>>>>> * If I configure tomcat to only use one thread, and use the default
>>>>>> 'HTTP/1.1' connector, the problem disappears (but response-times are
>>>>>> very slow).
>>>>>> * Using 4 threads + 'HTTP/1.1', the problem appears very fast. (one
>>>> or
>>>>>> two reloads)
>>>>>> * Using the 'Nio' connector and 4 threads, the problem appears, but
>>>> not
>>>>>> so fast (3-4 reloads)
>>>>>> * Using the 'Nio' connector with only one thread, is about the same
>>>> as
>>>>>> Nio with several threads.
>>>>>>
>>>>>>
>>>>>> Best regards,
>>>>>>
>>>>>> Heiko
>>>>>>
