https://bz.apache.org/bugzilla/show_bug.cgi?id=59122

            Bug ID: 59122
           Summary: Browser send back to tomcat "likely valid" JSESSIONID
                    but tomcat recreate session and response to browser a
                    renewed JESSIONID
           Product: Tomcat 7
           Version: unspecified
          Hardware: PC
            Status: NEW
          Severity: critical
          Priority: P2
         Component: Catalina
          Assignee: dev@tomcat.apache.org
          Reporter: lanarima...@gmail.com

In production environment - tomcat_7_0_53 behind Apache/mod_jk - our customers
report problems caused by random lost session issues.

We have investigated enabling AccessLogValve and to exclude bad session
handling in request processing, like programmatically invoking of
session.invalidate or session.setMaxTimeInterval etc.., we have catched and
logged HttpSessionEvent via HttpSessionListener interface implementation.

####################################################################################
##### Logging by AccessLogValve
##### At first access time
82.112.204.155 - - [03/Mar/2016:08:27:03 +0100] "GET
/rdsv5i/servlet/custom-logon/clienti-asp HTTP/1.1"
Cookie="__utma=31431036.270103424.1433757878.1456913762.1456990022.212;
__utmz=31431036.1433757878.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
__utmb=31431036.1.10.1456990022; __utmt=1; __utmc=31431036;
CustomLogonServlet.company=IAP; user=caruso;
rds_home_page_logon=%2Frdsv5i%2Fservlet%2Fcustom-logon%2Fclienti-asp%3F1456913769327"
Set-Cookie="JSESSIONID=ADDBC908E913C159A330C746ABFE2340; Path=/rdsv5i; Secure"

##### User work without problems for 10 minutes:
82.112.204.155 - - [03/Mar/2016:08:37:58 +0100] "POST
/rdsv5i/spoolviewer/spoolavailable.jsp HTTP/1.1"
Cookie="AlreadyConnectedGUID=f34dc1bb-a117-4405-a40d-289c73e07de9;
JSESSIONID=ADDBC908E913C159A330C746ABFE2340;
__utma=31431036.270103424.1433757878.1456913762.1456990022.212;
__utmz=31431036.1433757878.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
__utmb=31431036.1.10.1456990022; __utmc=31431036;
CustomLogonServlet.company=IAP; user=caruso;
rds_home_page_logon=%2Frdsv5i%2Fservlet%2Fcustom-logon%2Fclienti-asp%3F1456990031203"
Set-Cookie="-"

#### Suddenly Tomcat send Set-Cookie
82.112.204.155 - - [03/Mar/2016:08:38:06 +0100] "POST
/rdsv5i/spoolviewer/spoolavailable.jsp HTTP/1.1"
Cookie="AlreadyConnectedGUID=f34dc1bb-a117-4405-a40d-289c73e07de9;
JSESSIONID=ADDBC908E913C159A330C746ABFE2340;
__utma=31431036.270103424.1433757878.1456913762.1456990022.212;
__utmz=31431036.1433757878.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
__utmb=31431036.1.10.1456990022; __utmc=31431036;
CustomLogonServlet.company=IAP; user=caruso;
rds_home_page_logon=%2Frdsv5i%2Fservlet%2Fcustom-logon%2Fclienti-asp%3F1456990031203"
Set-Cookie="JSESSIONID=28C983BAE315B709093B357C0DE7810D; Path=/rdsv5i; Secure"

and session lost issues...

#### Logging by my HttpSessionListener
##### At first access time
03-Mar-2016 08:27:03.437 INFO [ajp-apr-8109-exec-5]
com.rds_software.RdsUtil.http.HttpSessionEventsLogger.sessionCreated
id="ADDBC908E913C159A330C746ABFE2340"

#### Suddenly Tomcat send Set-Cookie
03-Mar-2016 08:38:06.358 INFO [ajp-apr-8109-exec-6]
com.rds_software.RdsUtil.http.HttpSessionEventsLogger.sessionCreated
id="28C983BAE315B709093B357C0DE7810D"

#### At first access time session destroying
03-Mar-2016 09:08:43.365 INFO
[ContainerBackgroundProcessor[StandardEngine[Catalina]]]
com.rds_software.RdsUtil.http.HttpSessionEventsLogger.sessionDestroyed
id="ADDBC908E913C159A330C746ABFE2340" lastAccessedTime="08:37"
maxInactiveTimeInterval="1800" stackTrace="Stacktrace: 
org.apache.catalina.session.StandardSession.expire(StandardSession.java:806)
  org.apache.catalina.session.StandardSession.isValid(StandardSession.java:656)
  org.apache.catalina.session.ManagerBase.processExpires(ManagerBase.java:532)
 
org.apache.catalina.session.ManagerBase.backgroundProcess(ManagerBase.java:517)
 
org.apache.catalina.core.ContainerBase.backgroundProcess(ContainerBase.java:1352)
 
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1530)
 
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1540)
 
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.processChildren(ContainerBase.java:1540)
 
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1519)
"
####################################################################################

My question is: 
How is possible tomcat create a new session at 08:38:06 when browser sent back
JSESSIONID=ADDBC908E913C159A330C746ABFE2340 and
ADDBC908E913C159A330C746ABFE2340 have been destroyed at 9:08:46?

At 08:38:06 Session ADDBC908E913C159A330C746ABFE2340 not was valid?

I worked heavy for a week to code a test case to reproduce this strange
behaviour but unsuccesfully.

Every suggest or idea is appreciate.

-- 
You are receiving this mail because:
You are the assignee for the bug.

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@tomcat.apache.org
For additional commands, e-mail: dev-h...@tomcat.apache.org

Reply via email to