Session attributes are getting lost sometime in concurrent request i guess #i added lockingmode to All but it does not seems hellping at all #283
Comments
erLovepreet
changed the title
|
The provided logs do not provide all information, therefore I'm not sure if anything relevant is missing. Please share the full log of the related requests. |
|
Exactly what information you wants....because i have pasted all related logs in the post (these are tomcat logs ) |
|
Are you sure you didn't remove parts of the logs? There should some more stuff being logged. |
|
Sir these are the exact logs i havn't changed any thing as far i know FINE: Starting for session id 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81 --------------------------------------------setsession------------------------isLoggedIn Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.MemcachedSessionService backupSession Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.BackupSessionService backupSession |
|
Ok, thanks! Where does It seems as if As it seems, How are you changing the session id? |
|
Where does --------------------------------------------setsession------------------------isLoggedIn come from? Is this logged by POST /zcubator93/control/authenticate? It seems as if POST /zcubator93/control/ssologin and POST /zcubator93/control/authenticate are running in parallel, is this possible? Actual case is ssologin invalidate the session and authenticate makes new session and sets a attribute but after send redirect from authenticate the variable is not visible on next jsp. because session is not get updated after authenticate.jsp ...and next jsp gets session from memcached and getting value null- |
|
I'm missing the "Request starting" logs for ssologin and authenticate. What
|
|
sorry for that sir, FINE: >>>>>> Request starting: POST /zcubator93/control/ssologin (requestedSessionId D88BB292CB7EFE970F1EA02AD9E6459F.tomcat81) ================= I hope this time you have all the logs . please let me know if i m missing anything What do you mean with "ssologin calls authenticate", can you describe this is more detail? |
This shall support the case where the request creating the session invokes another page (e.g. via forward) that then runs "in parallel". Refs #283
|
Ok, I think I found s.th. Can you try the latest snapshot? |
|
sir the problem is still there ... :( |
|
I had a theory for the reason (yes, related to concurrent requests), but it
|
|
@erLovepreet Can you please also update to the latest version 1.9.1 and share logs for concurrent requests / the issue? |
|
Hi sir, Sorry for late reply , i got that problem and i applied temporary solution for that problem. This doesnot even work in our project environment now about new jars i am sharing logs of login time and very next request login time logs Feb 11, 2016 11:58:14 AM de.javakaffee.web.msm.RequestTrackingHostValve invoke ......................................this is where isLoggedin in set in session......................... canAccessCustomerFeedback>>>>>>>>>>>>>>>>>>>>>>>>>>>>>true next request logs Feb 11, 2016 11:58:45 AM de.javakaffee.web.msm.RequestTrackingHostValve invoke |
|
Ok. My next hypothesis is that the issue is caused by assets (png, jpg
|
|
Sir, here's the log Feb 12, 2016 12:37:45 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke tabUrl==========null .......................I gona call invalidate........................... Feb 12, 2016 12:37:45 PM de.javakaffee.web.msm.MemcachedBackupSessionManager removeInternal ......................................this is where isLoggedin in set in session......................... Feb 12, 2016 12:37:46 PM de.javakaffee.web.msm.LockingStrategy onAfterBackupSession One thing i want you to know that this only occurs when previous request takes too much time to execute. means we can reproduce it with the help of thread.sleep(). |
|
Can you create a reproducable sample based on https://github.com/magro/memcached-session-manager/tree/master/samples? Then I can check and analyze this. |
|
@erLovepreet How's it going, can you create a reproducable sample for your issue? |
|
I also noticed a similar issue. Digging into the logs I found the following stack trace: Configuration: Thanks for any hint. If I can help with some more detailed logs, please let me know how to enable them. Thanks. |
|
@mirion can you reproduce this issue on your local machine or does it only happen in production from time to time? I'll have a look at the NPE soon. |
|
@mirion The NPE at this line is really weird - is it possible that this happened during startup or shutdown phase? Did you see it one or during a very short period, ofter several times during otherwise normal operation? |
|
@magro, The NPE may indeed appear during an app reload as I found the stack trace into eclipse. I noticed initially that the sessions are expiring very quickly (few minutes). Since we just moved to tomcat 8, I was thinking that we missed some configuration but I checked the settings and everything is looking fine. I can now reproduce the problem (not the NPE) into my local development environment. If you could give me some instructions on how to debug it, we may make some progress and eventually fix it. The configuration that I'm using is the following (into context.xml):
I also noticed something very strange. It looks like the session is found into memcache but it is not restored correctly/completely. For example, I'm storing the database connection URL and after the session restore I'm getting a NPE when trying to use that URL. I have the main credentials object but they are missing that particular piece of information. This is really weird. Do you think that it may be an issue with kryo? On the other hand, we are using kryo for other stuff and I didn't notice any problem. |
|
@mirion Great that you're able to reproduce it!
|
|
Btw, I just noticed that URLs in fact cannot be (de)serialized with kryo... |
|
@magro Thanks a lot.
Thnaks. |
|
We are not saving the URL as an object but the coordinates of the server and we later compose the JDBC URL to build the datasource if needed. I'll make a code inspection to check if the session manager bug is not triggering in fact a bug into our code, that otherwise can't arise because we are supposed to have a good session with all the data available. In any case, beyond this serialization issue, the session expiration still exists. |
|
Re 1: you shouldn't have to do anything, I just wanted to mention that things in tomcat had changed. The mentioned commit handles this already. Re 3: not sure what happens when different webapps share the same session - things may go wrong (because the manager/msm has no longer control) |
|
@magro Re 3. There was a problem with my local tomcat configuration. The Context didn't have |
|
Great to hear that it's working now! Although I'd say that for each webapp a dedicated manager instance exists, which is necessary for appropriate lifecycle handling. Strange to hear that the session timeout in web.xml doesn't work - was it the webapps web.xml or the global one? Does it also not work without msm? |
|
I'm sure that you know better how the session managers are working. I didn't dig into your code, but I suppose that you (synchronously?) save the session into the storage (memcache). Therefore even if the manager is different, the session can be can be recovered by another webapp. Since I never noticed any issue, even under heavy load (during load tests) I arrived at the conclusion that the sessions data is effectively shared. And it looks that I'm not the only one using the same procedure: http://forum.broadleafcommerce.org/viewtopic.php?t=4184 If my findings are supported by your code, it may be useful to put this info into the wiki. If I'm just benefiting from a side effect, it may make sense to harden this path and fully embrace it. Shared session managers are a common issue. It was the global web.xml. I didn't remove the setting but I noticed that it is useless. Will check again when I'll have more time available. |
|
To have synchronous session backup you must configure sessionBackupAsync=false. Parallel requests going to different webapps will produce race conditions (if they're both/all write/modify the session). If it's working for you this is great, but it's nothing I'd publicly support (right now). To handle parallel requests maybe session locking as it's done for non-sticky sessions might be a way, but this would have to be implemented / changed so that it can work with sticky sessions. |
|
I understand. I was assuming from the beginning that it is possible to get race conditions. Therefore the session is created once (at login) and never updated. I'll follow your advice and set Thanks a lot again for your help and your great software. |
|
You're welcome :-) If the session is not updated (by parallel requests) and there are no very fast subsequent requests you could also stay with sessionBackupAsync=true (if this is already working for you :-)) Cheers |
|
Hello, I'm working on the same project as mirion. |
|
@adriansn It's fine to continue here if it's not a totally different story :-) |
|
Normally, this is the same issue. Sorry for the delay in my response, was trying to minimise the changes, but it's not easy... I tried to remove the references to session time-related attributes and to the session attributes themselves, but the results were not satisfying. |
|
Sorry, forgot one "detail". In order to ensure compatibility with previous versions of Tomcat, I added the following method to |
here are my memcached configuration
FINE: Starting for session id 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81
Jan 09, 2016 11:10:29 PM de.javakaffee.web.msm.BackupSessionTask doBackupSession
FINE: Trying to store session in memcached: 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81
Jan 09, 2016 11:10:29 PM de.javakaffee.web.msm.BackupSessionTask call
FINE: Finished for session id 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81, returning status SUCCESS
Jan 09, 2016 11:10:29 PM de.javakaffee.web.msm.LockingStrategy onAfterBackupSession
FINE: Stored session validity info for session 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81
Jan 09, 2016 11:10:29 PM de.javakaffee.web.msm.RequestTrackingHostValve logDebugRequestSessionCookie
FINE: Have request session cookie: domain=null, maxAge=-1, path=null, value=D4B1CE0FFDF440D7374D0A3A3F365BBB.tomcat81, version=0, secure=false
Jan 09, 2016 11:10:29 PM de.javakaffee.web.msm.RequestTrackingHostValve logDebugResponseCookie
FINE: Request finished, with Set-Cookie header: JSESSIONID=7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81; Path=/contextpath/; HttpOnly
Jan 09, 2016 11:10:29 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke
FINE: <<<<<< Request finished: POST /previousRequest ==================
//here i am trying to set some attribute.
--------------------------------------------setsession------------------------isLoggedIn
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.MemcachedSessionService backupSession
FINE: No session found in session map for 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.LockingStrategy onBackupWithoutLoadedSession
FINE: Stored session validity info for session 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.RequestTrackingHostValve logDebugRequestSessionCookie
FINE: Have request session cookie: domain=null, maxAge=-1, path=null, value=7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81, version=0, secure=false
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke
FINE: <<<<<< Request finished: POST /someRequest ==================
//request which sets the attribute is over
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.LockingStrategy pingSession
FINE: The session was ping'ed successfully.
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.RequestTrackingHostValve invoke
//someother request
FINE: >>>>>> Request starting: GET /someother request (requestedSessionId 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81) ==================
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.MemcachedSessionService loadFromMemcached
FINE: Loading session from memcached: 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.MemcachedSessionService loadFromMemcached
FINE: Found session with id 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81
--------------------------getting attribute from same session but getting null
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.BackupSessionService backupSession
//now it is trying to update the session in memcahed but session is alredy dirty read by previous request
FINE: Starting for session id 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.BackupSessionTask call
FINE: Starting for session id 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.BackupSessionTask call
FINE: Finished for session id 7ECDF6FB9A2DF19ECD4B0C7BFA98D9AF.tomcat81, returning status SKIPPED
Jan 09, 2016 11:10:30 PM de.javakaffee.web.msm.LockingStrategy onAfterBackupSession
i have tried it with locking mode also but problem is still exists
According to me the problem is thread which is calling BackupSessionTask for backup , it is taking time to update the session in memcached mean while other request do dirty read
if my guess was right you should have wait for thread before assigning session from memcached to other request
if i am missing some configuration please let me know
Thanks in advance
The text was updated successfully, but these errors were encountered: