Re: [jetty-users] Untimely session timeout

[Pavel Jbanov <pavel.jbanov@xxxxxxxxx>]

Hi,

I've added some more debug info into to my logs, so I think I can narrow the question down a bit...

It looks like the second session with the same ID is created on another context. I have two apps running on the same container (myapp and myapp_public):

[14-12-2010 08:57:51] sessionCreated kbhp3wpetz16yludgsm3c5s7 url:http://demo1.myapp.com/my_app/Home.action

[14-12-2010 09:21:40] sessionCreated kbhp3wpetz16yludgsm3c5s7 url:http://demo1.myapp.com/my_app_public/index.jsp

[14-12-2010 09:51:52] sessionDestroyed id:kbhp3wpetz16yludgsm3c5s7 created:14-12-2010 09:21:40 lastAccess:14-12-2010 09:41:13

[14-12-2010 09:51:52] sessionDestroyed id:kbhp3wpetz16yludgsm3c5s7 created:14-12-2010 08:57:51 lastAccess:14-12-2010 09:21:38

So as you can see, first session is created on "/my_app" and second session is created on "/my_app_public". The question is why does it use the same session ID? Could it be because the context path of the first app is a substring of the context path of the second app?

Also, why does the destruction of one session cause the destruction of all sessions with the same ID? Each context has it's own HashSessionManager.

<?xml version="1.0"  encoding="ISO-8859-1"?>

<Configure class="com.myapp.container.MyWebAppContext">

<Set name="contextPath">/my_app</Set>

<Set name="war">d:\apps\my_app</Set>

<Set name="displayName">MyApp</Set>

<Set name="applicationId">MyApp</Set>

<Set name="defaultsDescriptor">d:\etc/webdefault.xml</Set>

<Set name="copyWebDir">true</Set>

<Set name="parentLoaderPriority">false</Set>

<Set name="sessionTimeout">1800</Set>

<Set name="sessionHandler">

  <New class="com.myapp.container.DebugSessionHandler">

    <Arg>

      <New class="com.myapp.container.DebugHashSessionManager">

        <Set name="maxInactiveInterval">1800</Set>

      </New>

    </Arg>

  </New>

</Set>

</Configure>

<?xml version="1.0"  encoding="ISO-8859-1"?>

<Configure class="com.myapp.container.MyWebAppContext">

<Set name="contextPath">/my_app_public</Set>

<Set name="war">d:\apps\my_app_public</Set>

<Set name="displayName">MyAppPublic</Set>

<Set name="applicationId">MyAppPublic</Set>

<Set name="defaultsDescriptor">d:\etc/webdefault.xml</Set>

<Set name="copyWebDir">true</Set>

<Set name="parentLoaderPriority">false</Set>

<Set name="sessionTimeout">1800</Set>

<Set name="sessionHandler">

  <New class="com.myapp.container.DebugSessionHandler">

    <Arg>

      <New class="com.myapp.container.DebugHashSessionManager">

        <Set name="maxInactiveInterval">1800</Set>

      </New>

    </Arg>

  </New>

</Set>

</Configure>

Any ideas would be very appreciated. Thank you.

Pavel

On Thu, Dec 9, 2010 at 3:46 PM, Pavel Jbanov <pavel.jbanov@xxxxxxxxx> wrote:

Hi,

I'm trying to investigate really strange untimely session timeouts, happening relatively regular for some clients, and looking for possible ideas to look into, because I'm starting to run out of ideas of my own.

I'm running Jetty 7.1.6. I've added a session listener and added debug statements into HashSessionManager and here is the sequence of events:

[09-12-2010 12:51:42] sessionCreated p7wexn203xb3vmf4fp54l3uv

[09-12-2010 12:51:42] attributeAdded to p7wexn203xb3vmf4fp54l3uv

[09-12-2010 01:19:43] access id:p7wexn203xb3vmf4fp54l3uv lastAccess:31-12-1969 05:00:00 ttl:1800s

[09-12-2010 01:19:44] access id:p7wexn203xb3vmf4fp54l3uv lastAccess:09-12-2010 12:51:42 ttl:1800s

[09-12-2010 01:21:07] access id:p7wexn203xb3vmf4fp54l3uv lastAccess:09-12-2010 01:20:46 ttl:1800s

[09-12-2010 01:24:05] access id:p7wexn203xb3vmf4fp54l3uv lastAccess:09-12-2010 01:22:06 ttl:1800s

[09-12-2010 01:24:13] sessionCreated p7wexn203xb3vmf4fp54l3uv

[09-12-2010 01:24:13] access id:p7wexn203xb3vmf4fp54l3uv lastAccess:31-12-1969 05:00:00 ttl:1800s

[09-12-2010 01:24:18] access id:p7wexn203xb3vmf4fp54l3uv lastAccess:09-12-2010 01:24:13 ttl:1800s

[09-12-2010 01:28:26] access id:p7wexn203xb3vmf4fp54l3uv lastAccess:09-12-2010 01:28:25 ttl:1800s

[09-12-2010 01:43:05] access id:p7wexn203xb3vmf4fp54l3uv lastAccess:09-12-2010 01:43:05 ttl:1800s

[09-12-2010 01:51:18] access id:p7wexn203xb3vmf4fp54l3uv lastAccess:09-12-2010 01:50:22 ttl:1800s

[09-12-2010 01:54:40] sessionDestroyed id:p7wexn203xb3vmf4fp54l3uv created:09-12-2010 12:51:42 lastAccess:09-12-2010 01:53:49

[09-12-2010 01:54:40] attributeRemoved p7wexn203xb3vmf4fp54l3uv

[09-12-2010 01:54:40] sessionDestroyed id:p7wexn203xb3vmf4fp54l3uv created:09-12-2010 01:24:13 lastAccess:09-12-2010 01:24:19

[09-12-2010 01:55:00] sessionCreated sj8emozrd5m1rcv3dtc2um5k

[09-12-2010 01:55:00] attributeAdded sj8emozrd5m1rcv3dtc2um5k

So what I see from the logs, is that the session is created at 12:51, but then at 01:24 another session with the same ID is created and later that second session expires at 1:54 (30 minutes later) and it get the first (active) session destroyed as well probably because they have the same ID. 

Does it make sense? Is it even possible to create another session with the same ID?

Any suggestions/ideas are very appreciated.

Thank you,

Pavel