Skip to content

Validity data and session data have mismatching TTL #442

Description

@jungm

Session data appears to have a longer TTL in redis than validity data, causing issues with proper session expiration. The following line gets logged a couple hundred times before a java internal error appears, hinting at a StackOverflowError:

14-Feb-2022 14:21:34.684 WARNING [http-nio-8080-exec-4] de.javakaffee.web.msm.LockingStrategy.onAfterLoadFromMemcached No validity info available for session AB599463FEAA5BB99A84FF5FC48B2F26
14-Feb-2022 14:21:34.689 WARNING [http-nio-8080-exec-4] de.javakaffee.web.msm.LockingStrategy.onAfterLoadFromMemcached No validity info available for session AB599463FEAA5BB99A84FF5FC48B2F26
14-Feb-2022 14:21:34.695 WARNING [http-nio-8080-exec-4] de.javakaffee.web.msm.LockingStrategy.onAfterLoadFromMemcached No validity info available for session AB599463FEAA5BB99A84FF5FC48B2F26
14-Feb-2022 14:21:34.700 WARNING [http-nio-8080-exec-4] de.javakaffee.web.msm.LockingStrategy.onAfterLoadFromMemcached No validity info available for session AB599463FEAA5BB99A84FF5FC48B2F26
14-Feb-2022 14:21:34.705 WARNING [http-nio-8080-exec-4] de.javakaffee.web.msm.LockingStrategy.onAfterLoadFromMemcached No validity info available for session AB599463FEAA5BB99A84FF5FC48B2F26
14-Feb-2022 14:21:34.710 WARNING [http-nio-8080-exec-4] de.javakaffee.web.msm.LockingStrategy.onAfterLoadFromMemcached No validity info available for session AB599463FEAA5BB99A84FF5FC48B2F26
14-Feb-2022 14:21:34.715 WARNING [http-nio-8080-exec-4] de.javakaffee.web.msm.LockingStrategy.onAfterLoadFromMemcached No validity info available for session AB599463FEAA5BB99A84FF5FC48B2F26
*** java.lang.instrument ASSERTION FAILED ***: "!errorOutstanding" with message transform method call failed at ./src/java.instrument/share/native/libinstrument/JPLISAgent.c line: 873

Looking at the callstack this seems to be a side effect of running MSM in conjunction with Apache OpenWebBeans.

Session Manager Config:

    <Manager className="de.javakaffee.web.msm.MemcachedBackupSessionManager"
             memcachedNodes="redis://localhost:6379"
             sticky="false"
             sessionBackupAsync="false"
             sessionBackupTimeout="1000"
             requestUriIgnorePattern=".*\.(ico|png|gif|jpg|css|js|html|htm|woff).*"
             storageKeyPrefix="context"/>

Redis version:
6.2.6

Jedis version:
3.8.0

memcached-session-manager version:
2.3.2

This is what the issue looks like in the redis CLI:

127.0.0.1:6379> KEYS *
1) "AB599463FEAA5BB99A84FF5FC48B2F26"
2) "validity:AB599463FEAA5BB99A84FF5FC48B2F26"
127.0.0.1:6379> TTL validity:AB599463FEAA5BB99A84FF5FC48B2F26
(integer) 42
127.0.0.1:6379> TTL AB599463FEAA5BB99A84FF5FC48B2F26
(integer) 101

This appears to be caused by this line, though I'm not sure if this multiplication was implemented intentionally

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions