Hi Martin,

We're sometimes getting logged out right after login, and this seems to be
the cause:

WARNING: Could not load session with id 17AF5E7156C86AF174CB72C64209CB9B-n1
from memcached.
java.lang.RuntimeException: The loaded object for sessionId
17AF5E7156C86AF174CB72C64209CB9B-n1 is not of required type byte[], but
java.lang.Integer

Stack trace from catalina.out https://gist.github.com/4207807
Config: https://gist.github.com/4207817 (asyncBackup, auto locking, 4
backup threads on a 4-virtual-core box).

- Is this something to do with async backup?
- I'm not sure why the original "seemed to be not existing anymore." that
you see in the log is happening.
- This has come up on the list before, and the problem then was servers
with out-of-sync clocks, but that is not the case here (using ntp and I
verified that times are in sync within 1 second).

Andy

Search Discussions

  • Martin Grotzke at Dec 4, 2012 at 10:02 pm
    Hi Andy,
    On 12/04/2012 08:55 PM, Andy O'Neill wrote:
    Hi Martin,

    We're sometimes getting logged out right after login, and this seems to
    be the cause:

    WARNING: Could not load session with id
    17AF5E7156C86AF174CB72C64209CB9B-n1 from memcached.
    java.lang.RuntimeException: The loaded object for sessionId
    17AF5E7156C86AF174CB72C64209CB9B-n1 is not of required type byte[], but
    java.lang.Integer

    Stack trace from catalina.out https://gist.github.com/4207807
    Config: https://gist.github.com/4207817 (asyncBackup, auto locking, 4
    backup threads on a 4-virtual-core box).

    - Is this something to do with async backup?
    According to the logs the session cannot be found in memcached, so
    changing to sync backup might be the solution.
    For non-sticky sessions I'd also recommend using sync backup, as you
    have better consistency. With async backup under high load (high latency
    for session update in memcached) some requests might work on an older
    version of the session - depending on the characteristics of the
    application.

    Maybe it would also be an option to just perform the first backup in
    sync mode (for new sessions) to have them available in memcached for
    later requests. This would be a change in msm for async mode.
    - I'm not sure why the original "seemed to be not existing anymore."
    that you see in the log is happening.
    This log is printed when the session should be "touched" in memcached
    but the session does not exist in memcached ("anymore" is misleading
    here, I just fixed the log message).

    According to the logs I'd say that there are some concurrent requests
    for the same session running. Either the request that triggered the logs
    mentioned above did not load the session, or another, concurrent request
    removed the session from the local session map.

    It would be helpful to have more context:
    - Do you have logs from previous requests for this session?
    - Do these logs belong to requests from the initial login action, or
    from the view right after login?
    - When is the session created, on login (maybe a rotated sessionId?), or
    already before login?
    - Do you see concurrent requests for this action/view (always/sometines)?
    - Do you have some kind of http request infos (requests targeting
    tomcat) for such a situation (e.g. from firebug, chrome dev tools)?


    msm already tries to handle concurrent requests as good as possible, but
    it seems there's room for improvement for the nonsticky sessions + async
    backup scenario.
    If you'd like to dig further into this I could provide an msm jar with
    some logs specifically targeting this issue to get more information (if
    you don't just want to change to sync backup).

    Cheers,
    Martin


    - This has come up on the list before, and the problem then was servers
    with out-of-sync clocks, but that is not the case here (using ntp and I
    verified that times are in sync within 1 second).

    Andy
  • Andy O'Neill at Dec 5, 2012 at 3:34 pm

    On Tue, Dec 4, 2012 at 5:02 PM, Martin Grotzke wrote:

    - Is this something to do with async backup?
    According to the logs the session cannot be found in memcached, so
    changing to sync backup might be the solution.
    For non-sticky sessions I'd also recommend using sync backup, as you
    have better consistency. With async backup under high load (high latency
    for session update in memcached) some requests might work on an older
    version of the session - depending on the characteristics of the
    application.
    This seems likely to me too. I will try synchronous backups (although I'm
    nervous about the performance impact).

    Maybe it would also be an option to just perform the first backup in
    sync mode (for new sessions) to have them available in memcached for
    later requests. This would be a change in msm for async mode.
    - I'm not sure why the original "seemed to be not existing anymore."
    that you see in the log is happening.
    This log is printed when the session should be "touched" in memcached
    but the session does not exist in memcached ("anymore" is misleading
    here, I just fixed the log message).

    According to the logs I'd say that there are some concurrent requests
    for the same session running. Either the request that triggered the logs
    mentioned above did not load the session, or another, concurrent request
    removed the session from the local session map.
    Almost certainly there are concurrent requests. In fact we have modified
    our app architecture in a way that is more likely to create concurrent
    requests. But looking at the apache log for this time there are not
    concurrent requests (see below).

    It would be helpful to have more context:
    - Do you have logs from previous requests for this session?
    There are no previous mentions of that session in the log

    - Do these logs belong to requests from the initial login action, or
    from the view right after login?
    Here's the apache log for this activity https://gist.github.com/4216495

    We see the initial login POST, then the post-login GET to /utility/ is
    redirected to login.html, so it looks like the initial login is successful
    but the next request fails.


    - When is the session created, on login (maybe a rotated sessionId?), or
    already before login?
    We require a new session on login. The return from j_spring_security_check
    sets a new JSESSIONID cookie. Ignore the favicon.ico requests. I'm going to
    fix that but that request doesn't hit tomcat.

    - Do you see concurrent requests for this action/view (always/sometines)?
    There's no concurrent request in this case. Loading the first view, before
    any AJAX, gets a redirect to login.

    - Do you have some kind of http request infos (requests targeting
    tomcat) for such a situation (e.g. from firebug, chrome dev tools)?

    I don't have this yet, sorry.
    msm already tries to handle concurrent requests as good as possible, but
    it seems there's room for improvement for the nonsticky sessions + async
    backup scenario.
    If you'd like to dig further into this I could provide an msm jar with
    some logs specifically targeting this issue to get more information (if
    you don't just want to change to sync backup).
    I will try changing to sync first and I will enable FINE logging.

    Thanks,
    Andy

Related Discussions

Discussion Navigation
viewthread | post
Discussion Overview
groupmemcached-session-manager @
categoriesmemcached
postedDec 4, '12 at 7:55p
activeDec 5, '12 at 3:34p
posts3
users2
websitememcached.org

2 users in discussion

Andy O'Neill: 2 posts Martin Grotzke: 1 post

People

Translate

site design / logo © 2022 Grokbase