Bug 56882 - "HTTP Status 503 - Servlet jsp is currently unavailable" after Context reload
"HTTP Status 503 - Servlet jsp is currently unavailable" after Context reload
Status: RESOLVED FIXED
Product: Tomcat 8
Classification: Unclassified
Component: Jasper
8.0.11
PC All
: P2 regression (vote)
: ----
Assigned To: Tomcat Developers Mailing List
:
Depends on:
Blocks:
  Show dependency tree
 
Reported: 2014-08-22 21:14 UTC by Marco
Modified: 2014-08-26 11:53 UTC (History)
0 users



Attachments
2014-08-23_tc8_56882_v1.patch (634 bytes, patch)
2014-08-23 15:29 UTC, Konstantin Kolinko
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Marco 2014-08-22 21:14:41 UTC
After a Context reload with Tomcat Manager all JSP calls with this.getServletContext().getRequestDispatcher("/jspname.jsp").forward(request, response); create a "HTTP Status 503 - Servlet jsp is currently unavailable" response. With Tomcat 8.0.9 and Tomcat 7.0.55 it works.
Comment 1 Konstantin Kolinko 2014-08-23 14:15:46 UTC
Ack. Reproducible with 8.0.11 using the examples webapp.

Steps:
1. Configure a user with manager-gui role in conf/tomcat-users.xml
2. Start Tomcat
3. Access "Include" and "Forward" JSP examples,
in two different tabs in Firefox
http://localhost:8080/examples/jsp/include/include.jsp
http://localhost:8080/examples/jsp/forward/forward.jsp

4. Go to Tomcat Manager web application and click "Reload" button on the examples 
webapp.

5. Reload (F5 in Firefox) the above example pages.
Expected: The same output as on step 3 though with diifferent time stamps.
Actual:

include.jsp gives:
[[[
In place evaluation of another JSP which gives you the current time: 1408802860131
by including the output of another JSP: :-) 
]]]
The second sentence had to contain a timestamp value. It is missing.

forward.jsp gives:
[[[
HTTP Status 503 - Servlet jsp is currently unavailable
]]]

There are no error messages in the logs.
Access logs have
127.0.0.1 - - [23/Aug/2014:18:07:37 +0400] "GET /examples/jsp/forward/forward.jsp HTTP/1.1" 503 1073
127.0.0.1 - - [23/Aug/2014:18:07:40 +0400] "GET /examples/jsp/include/include.jsp HTTP/1.1" 200 299
Comment 2 Konstantin Kolinko 2014-08-23 14:42:59 UTC
(In reply to Konstantin Kolinko from comment #1)
> Ack. Reproducible with 8.0.11 using the examples webapp.
> 
> Steps:
> 1. Configure a user with manager-gui role in conf/tomcat-users.xml

An alternative way to reproduce:
Skip step 1. and replace step 4. with:
- Touch webapps\examples\WEB-INF\web.xml 
- Wait several seconds, until a success message is logged on the console
Reloading Context with name [/examples] is completed

> 2. Start Tomcat
> 3. Access "Include" and "Forward" JSP examples,
> in two different tabs in Firefox
> http://localhost:8080/examples/jsp/include/include.jsp
> http://localhost:8080/examples/jsp/forward/forward.jsp
> 
> 4. Go to Tomcat Manager web application and click "Reload" button on the
> examples 
> webapp.
> 
> 5. Reload (F5 in Firefox) the above example pages.
> Expected: The same output as on step 3 though with diifferent time stamps.
> Actual:
> 
> include.jsp gives:
> [[[
> In place evaluation of another JSP which gives you the current time:
> 1408802860131
> by including the output of another JSP: :-) 
> ]]]
> The second sentence had to contain a timestamp value. It is missing.

The second sentence is missing more than just the timestamp.
The first part of it is missing as well. It had to be
[[[
To get the current time in ms by including the output of another JSP: 1408803609298 :-) 
]]]


The source code of include.jsp page is essentially the following:
[[[
<%@ page buffer="5kb" autoFlush="false" %>
<p>In place evaluation of another JSP which gives you the current time:
<%@ include file="foo.jsp" %>
<p> <jsp:include page="foo.html" flush="true"/> by including the output of another JSP:
<jsp:include page="foo.jsp" flush="true"/>
:-)
]]]

Thus both <jsp:include page="foo.html"> and <jsp:include page="foo.jsp"> are failing.


I wonder why it silently skips the failed pages. I expected it to produce an exception after the first failed include and abort the response.

The generated Java code for include.jsp does
[[[
      out.write("<p> ");
      org.apache.jasper.runtime.JspRuntimeLibrary.include(request, response, "foo.html", out, true);
      out.write(" by including the output of another JSP:\r\n");
]]]
and the JspRuntimeLibrary.include() method just calls RequestDispatcher.include(). Neither of them does any try/catch wrapping.

Why isn't javax.servlet.UnavailableException being thrown by RequestDispatcher?
Comment 3 Konstantin Kolinko 2014-08-23 15:29:38 UTC
Created attachment 31938 [details]
2014-08-23_tc8_56882_v1.patch

Patch that fixes the issue.
Just a fix, no test case included.

It is regression from Mapper rework. The new ContextVersion object was not registered in contextObjectToContextVersionMap map.


The contextObjectToContextVersionMap map is specific to Tomcat 8 mapper implementation. In Tomcat 7 there are separate Mapper instances in Service and Context, and this map is a replacement for context-specific Mapper in Tomcat 8. It is used to implement mapping for context-scoped rd.include() and rd.forward() calls.

Thus this bug is absent in 7.0.x, but it'd be better to add a testcase there as well.
Comment 4 Konstantin Kolinko 2014-08-25 11:43:19 UTC
(In reply to Konstantin Kolinko from comment #2)
> > Actual:
> > 
> > include.jsp gives:
> > [[[
> > In place evaluation of another JSP which gives you the current time:
> > 1408802860131
> > by including the output of another JSP: :-) 
> > ]]]
> > The second sentence had to contain a timestamp value. It is missing.
> 
> The second sentence is missing more than just the timestamp.
> The first part of it is missing as well.
>
> (...)
> 
> I wonder why it silently skips the failed pages. I expected it to produce an
> exception after the first failed include and abort the response.
> 

Apparently there is some design feature for included pages.
I do not plan to discuss it here. Just writing down the findings.

Ch.9.3 The Include Method (servlet-3_1-final.pdf), says
"The target servlet of the include method has access to all aspects of the request object, but its use of the response object is more limited." <...> "It
cannot set headers or call any method that affects the headers of the response, with the exception of the HttpServletRequest.getSession() and
HttpServletRequest.getSession(boolean) methods."

Technically, processing of unavailable servlets here in done in o.a.c.core.ApplicationDispatcher.invoke() as
1. Log a warning with wrapper.getLogger().warn(...)
2. hresponse.sendError(HttpServletResponse.SC_SERVICE_UNAVAILABLE, ...)


The warning is not logged, because logger.getHandlers() returns an empty list for all loggers in hierarchy chain. I do not know why that happens, but it might be expected for a stopped web application. (The request was mapped to a stopped ContextVersion due to this mapper bug).

The HttpServletResponse.sendError() call is ignored. (o.a.c.connector.Response#sendError(...)).
Comment 5 Konstantin Kolinko 2014-08-25 13:49:42 UTC
Fixed in trunk with r1620326 and will be in 8.0.12.

I will work on backporting the tests to Tomcat 7.
Comment 6 Konstantin Kolinko 2014-08-26 11:53:33 UTC
The test was backported to Tomcat 7 in r1620577 (to be in 7.0.56).
It passes successfully. There is no such bug in Tomcat 7.