Bug 51812 - Tomcat access logging "tickles" session causing session to never time out
Summary: Tomcat access logging "tickles" session causing session to never time out
Status: RESOLVED INVALID
Alias: None
Product: Tomcat 7
Classification: Unclassified
Component: Catalina (show other bugs)
Version: 7.0.14
Hardware: PC All
: P2 normal (vote)
Target Milestone: ---
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2011-09-14 17:11 UTC by danlee5002
Modified: 2011-09-21 18:13 UTC (History)
0 users



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description danlee5002 2011-09-14 17:11:40 UTC
I have created a web app (servlet application) that does asynchronous hits from the browser to periodically fetch some status information and update the page.  These asynchronous hits are directed to a dedicated servlet in the same webapp that takes great pains to never touch the session so that the session access time is not modified.  The idea is that these asynchronous hits don't count as real hits else the session would never idle time out.

This worked fine on Tomcat-6.0.14.  Upgrading to Tomcat-7.0.14 causes a problem in that these asynchronous hits are updating the session access time.

I have traced the problem down to org.apache.catalina.valves.AccessLogValve.java.  When it is doing its logging, it is trying to fetch the "principal" object from the session and thus changing the session last access time.  This does not seem to be legitimate.

Here is the relevant code:

 /**
  * Enforce the security restrictions in the web application deployment
  * descriptor of our associated Context.
  *
  * @param request Request to be processed
  * @param response Response to be processed
  *
  * @exception IOException if an input/output error occurs
  * @exception ServletException if thrown by a processing element
  */
 @Override
 public void invoke(Request request, Response response)
    throws IOException, ServletException {

    if (log.isDebugEnabled())
        log.debug("Security checking request " +
            request.getMethod() + " " + request.getRequestURI());
    LoginConfig config = this.context.getLoginConfig();

    // Have we got a cached authenticated Principal to record?
    if (cache) {
        Principal principal = request.getUserPrincipal();
        if (principal == null) {
            Session session = request.getSessionInternal(false);  <- Session Ticked Here
            if (session != null) {
                principal = session.getPrincipal();
                if (principal != null) {
                    if (log.isDebugEnabled())
                        log.debug("We have cached auth type " +
                            session.getAuthType() +
                            " for principal " +
                            session.getPrincipal());
                    request.setAuthType(session.getAuthType());
                    request.setUserPrincipal(principal);
                }
            }
        }

Changing the source code so that cache=false, solves the problem and the session access time is not affected by these asynchronous hits.  I cannot find a way to set cache=false other than changing source.  Adding cache="false" to the Valve tag in server.xml seems to have no effect.  

It would be nice if this parameter were controllable or if the code did not have this characteristic.  Logging should not effect the user's session.
Comment 1 Mark Thomas 2011-09-21 12:32:58 UTC
This report does not make any sense. The code quoted is from AuthenticatorBase which has nothing to do with the AccessLogValve.

Secondly, I can't see any code path from the quoted code that would trigger an update to the sessions last accessed time. Neither can I see any such code in the AccessLogValve.

Finally, session expiration is tested by the Servlet TCK which every release of Tomcat 7.0.x has passed.
Comment 2 Konstantin Kolinko 2011-09-21 18:13:02 UTC
(In reply to comment #0)
> I cannot find
> a way to set cache=false other than changing source.  Adding cache="false" to
> the Valve tag in server.xml seems to have no effect.  

Authenticators can be configured with <Valve> tag, and "cache" is a valid and documented parameter there. E.g.,

http://tomcat.apache.org/tomcat-7.0-doc/config/valve.html#Basic_Authenticator_Valve