Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve session locking for parallel requests (in 1 tomcat) #196

Open
GoogleCodeExporter opened this issue Feb 1, 2016 · 0 comments
Open

Comments

@GoogleCodeExporter
Copy link

Given a non-sticky setup and session locking in place currently parallel 
requests (running in the same tomcat) don't share a session lock.

Additionally, with lockingMode "auto" requests are not registered as readonly 
requests if there's still a request active for the same session (indicated by 
log output like "FINE: Session xyz is still used by another request, skipping 
backup and (optional) lock handling/release.").


Originally reported here: 
https://groups.google.com/forum/#!topic/memcached-session-manager/FonXe0j6uqU


Here's a full log output:

Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke
FINE: >>>>>> Request starting: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxslow (requestedSessionId 
24467C542B9AD943769F8FDC458392E8) ==================
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.MemcachedSessionService 
loadFromMemcached
FINE: Loading session from memcached: 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke
FINE: >>>>>> Request starting: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxfast=1 (requestedSessionId 
24467C542B9AD943769F8FDC458392E8) ==================
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.ReadOnlyRequestsCache 
isReadOnlyRequest
FINE: Asked for readonly request: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxslow (true)
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke
FINE: >>>>>> Request starting: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxfast=3 (requestedSessionId 
24467C542B9AD943769F8FDC458392E8) ==================
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.MemcachedSessionService 
loadFromMemcached
FINE: Loading session from memcached: 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke
FINE: >>>>>> Request starting: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxfast=2 (requestedSessionId 
24467C542B9AD943769F8FDC458392E8) ==================
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.ReadOnlyRequestsCache 
isReadOnlyRequest
FINE: Asked for readonly request: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxfast=1 (false)
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.MemcachedSessionService 
loadFromMemcached
FINE: Loading session from memcached: 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy lock
FINE: Locking session 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategyAuto 
onBeforeLoadFromMemcached
FINE: Not getting lock for readonly request GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxslow
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.MemcachedSessionService 
loadFromMemcached
FINE: Loading session from memcached: 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy acquireLock
FINE: Locked session 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.ReadOnlyRequestsCache 
isReadOnlyRequest
FINE: Asked for readonly request: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxfast=3 (false)
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy lock
FINE: Locked session 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.MemcachedSessionService 
loadFromMemcached
FINE: Found session with id 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.ReadOnlyRequestsCache 
isReadOnlyRequest
FINE: Asked for readonly request: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxfast=2 (false)
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy lock
FINE: Locking session 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy lock
FINE: Locking session 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.MemcachedSessionService 
loadFromMemcached
FINE: Found session with id 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 10 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.MemcachedSessionService 
backupSession
FINE: Session 24467C542B9AD943769F8FDC458392E8 is still used by another 
request, skipping backup and (optional) lock handling/release.
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 10 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.RequestTrackingHostValve 
logDebugRequestSessionCookie
FINE: Have request session cookie: domain=null, maxAge=-1, path=null, 
value=24467C542B9AD943769F8FDC458392E8, version=0, secure=false
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke
FINE: <<<<<< Request finished: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxfast=1 ==================
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 20 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 20 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 40 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 40 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 80 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 80 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 160 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 160 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 320 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 320 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 500 millis now...
Feb 16, 2014 11:45:33 PM de.javakaffee.web.msm.LockingStrategy 
checkTimeoutAndWait
FINE: Could not aquire lock for session 24467C542B9AD943769F8FDC458392E8, 
waiting 500 millis now...
Feb 16, 2014 11:45:34 PM de.javakaffee.web.msm.LockingStrategy lock
WARNING: Reached timeout when trying to aquire lock for session 
24467C542B9AD943769F8FDC458392E8. Will use this session without this lock.
Feb 16, 2014 11:45:34 PM de.javakaffee.web.msm.LockingStrategy lock
WARNING: Reached timeout when trying to aquire lock for session 
24467C542B9AD943769F8FDC458392E8. Will use this session without this lock.
Feb 16, 2014 11:45:34 PM de.javakaffee.web.msm.MemcachedSessionService 
loadFromMemcached
FINE: Found session with id 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:34 PM de.javakaffee.web.msm.MemcachedSessionService 
backupSession
FINE: Session 24467C542B9AD943769F8FDC458392E8 is still used by another 
request, skipping backup and (optional) lock handling/release.
Feb 16, 2014 11:45:34 PM de.javakaffee.web.msm.RequestTrackingHostValve 
logDebugRequestSessionCookie
FINE: Have request session cookie: domain=null, maxAge=-1, path=null, 
value=24467C542B9AD943769F8FDC458392E8, version=0, secure=false
Feb 16, 2014 11:45:34 PM de.javakaffee.web.msm.MemcachedSessionService 
loadFromMemcached
FINE: Found session with id 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:34 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke
FINE: <<<<<< Request finished: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxfast=3 ==================
Feb 16, 2014 11:45:34 PM de.javakaffee.web.msm.MemcachedSessionService 
backupSession
FINE: Session 24467C542B9AD943769F8FDC458392E8 is still used by another 
request, skipping backup and (optional) lock handling/release.
Feb 16, 2014 11:45:34 PM de.javakaffee.web.msm.RequestTrackingHostValve 
logDebugRequestSessionCookie
FINE: Have request session cookie: domain=null, maxAge=-1, path=null, 
value=24467C542B9AD943769F8FDC458392E8, version=0, secure=false
Feb 16, 2014 11:45:34 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke
FINE: <<<<<< Request finished: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxfast=2 ==================
Feb 16, 2014 11:45:38 PM de.javakaffee.web.msm.BackupSessionService 
backupSession
FINE: Starting for session id 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:38 PM de.javakaffee.web.msm.BackupSessionService 
backupSession
FINE: Session attributes were not accessed since last backup/check, therefore 
we can skip this
Feb 16, 2014 11:45:38 PM de.javakaffee.web.msm.LockingStrategy 
onAfterBackupSession
FINE: Stored session validity info for session 24467C542B9AD943769F8FDC458392E8
Feb 16, 2014 11:45:38 PM de.javakaffee.web.msm.ReadOnlyRequestsCache 
readOnlyRequest
FINE: Registering readonly request: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxslow
Feb 16, 2014 11:45:38 PM de.javakaffee.web.msm.LockingStrategy pingSession
FINE: The session was ping'ed successfully.
Feb 16, 2014 11:45:38 PM de.javakaffee.web.msm.RequestTrackingHostValve 
logDebugRequestSessionCookie
FINE: Have request session cookie: domain=null, maxAge=-1, path=null, 
value=24467C542B9AD943769F8FDC458392E8, version=0, secure=false
Feb 16, 2014 11:45:38 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke
FINE: <<<<<< Request finished: GET 
/msm-sample-webapp-1.0-SNAPSHOT/AjaxServlet?ajaxslow ==================

Original issue reported on code.google.com by martin.grotzke on 16 Feb 2014 at 11:15

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

No branches or pull requests

1 participant