S.deleteCookie and S.addCookie do nothing when called from LiftRules.earlyInStateful

[Trepi Dacious]

I've been working on an extended session system, it's very similar to ProtoExtendedSession, but uses my own interface to MongoDB. I've used the same approach of responding to user login/logout by creating and deleting a cookie with an id corresponding to a session record. This works well when cookies are created/deleted in response to the user logging in with a form and logging out by visiting a page, and cookies appear/disappear as expected in Chrome resources view. 

However I'm not seeing any effect from the same cookie code when it runs as part of the handler in LiftRules.earlyInStateful. On automatic login, the same login handler runs and this should delete the existing cookie and create a new one. I've added logging around the S.addCookie and S.deleteCookie calls, as well as S.notice calls, and these all happen as expected, with notices appearing on the rendered page, but the browser does not see any corresponding changes to the cookie - I'm just left with the old cookie in the browser. I've checked the responses and they only have the lift session cookie, the Chrome resources view just shows the old cookie. This means that only the first "automatic" login works, then the next one fails as the browser is out of sync.

I've also tried adding a simple S.addCookie in the earlyInStateful handler, that runs every time and just sets a cookie with another name and value as the current time in millis - this seems to work and the cookie is updated on page views.

If anyone wants to check the code that would be great - the important file is fairly short and is at https://github.com/trepidacious/boxes-sbt/blob/master/liftdemo/src/main/scala/boxes/lift/user/ExtendedSession.scala The full app runs from sbt in project liftdemo, and needs a mongodb running locally.

If anyone can recommend any further debug steps, or any additional requirements for using S.add/deleteCookie I would be very grateful!

Thanks,

Ben.

[Antonio Salazar Cardozo]

Is this as a response to an AJAX request or a regular request?

Thanks,

Antonio

[Trepi Dacious]

I think it will always be a normal request - in testing so far I've just been accessing index.html. In theory a user could visit any page when restarting their extended session, but they will need to get that page itself via a normal request before any AJAX requests are triggered.

Thanks,

Ben.

[Antonio Salazar Cardozo]

So just to clarify, when accessing index.html, using S.addCookie isn't working? Any chance you can post an example project (https://www.assembla.com/spaces/liftweb/wiki/Posting_example_code)?

Thanks,

Antonio

[Trepi Dacious]

So just to clarify, when accessing index.html, using S.addCookie isn't working? Any chance you can post an example project (https://www.assembla.com/spaces/liftweb/wiki/Posting_example_code)

Yes that's right - although specifically S.deleteCookie and S.addCookie are not working when they are called from earlyInStateful, in other places they work. At the moment the code in https://github.com/trepidacious/boxes-sbt/ shows the problem (it's the liftdemo subproject, and it needs a local mongo database and a gmail login to send validation emails), but I'll have a go at stripping it down as much as I can to make a better test case, I should be able to at least get rid of the email requirement.

Thanks,

Ben.

[Antonio Salazar Cardozo]

Cool, let us know when you've got that stripped down version. I definitely want to see what's up, because I went trawling in the code and it seemed like earlyInStateful should absolutely be setting cookies as desired.

Thanks,

Antonio

[Anton Khodakivskiy]

I have similar issue but mine is more narrow. Setting cookies in earlyInStateful generally works, but not when the request is missing or has expired JSESSIONID. So if I manually remove JSSESSION id, and then hit refresh on index.html, then S.addCookie and S.removeCookie won't do anything. This is quite annoying because the extended session functionality is completely broken due to this issue because I can't reset extended session cookie when JSESSIONID is abscent.

[Trepi Dacious]

I have similar issue but mine is more narrow. Setting cookies in earlyInStateful generally works, but not when the request is missing or has expired JSESSIONID. So if I manually remove JSSESSION id, and then hit refresh on index.html, then S.addCookie and S.removeCookie won't do anything. This is quite annoying because the extended session functionality is completely broken due to this issue because I can't reset extended session cookie when JSESSIONID is abscent.

I did some testing for this specific situation, and in my case if I just always set a cookie from earlyInStateful, with the current time, that is reliable. This also applies if the JSESSIONID is deleted, or if the server is restarted so it has to set a new session id.

What I have found is that the cookies only fail to add/delete if I actually log the user in - this consists of just setting a single SessionVar (with the id of the logged-in user). If I do a "fake" login where I check the cookie, look up the extended session in database, then delete the old cookie and create a new one, then just S.notice("Would log in here...") then the cookies are deleted and added as expected. If I change the S.notice to the actual call to update the SessionVar, then it logs in but does NOT update the cookies.

So it looks like setting a SessionVar breaks cookies for that page response?

[Antonio Salazar Cardozo]

Again, if I can get a repeatable flow in a sample app, I can see what's happ'nin' :) As it is, there seems to be no reason why setting a SessionVar would break the cookies. The same is true for JSESSIONID loss breaking it. Small, focused example apps that showcase this behavior would be really useful.

Thanks,

Antonio

[Trepi Dacious]

Yup, still working on that ;) The main thing now is that I think I've got the important bits to trigger the bug - earlyInStateful combined with setting a SessionVar, so it shouldn't need much code in the test case. The problem was a bit mysterious before since I wasn't sure what I was doing to trigger it. Now I just have to get round to actually writing the test case...

Thanks,

Ben.

[Anton Khodakivskiy]

https://github.com/akhodakivskiy/lift-sessions-bug

Alright, I just have put together a sample project that reproduces the bug Trepi described.

Steps to reproduce:

- Log in as Anton, Trepi, or Antonio. This will set the EXT_SESSION_TEST cookie value to the user name.

- Delete JSESSIONID or restart the server

- it will read the EXT_SESSION_TEST cookie, make sure that its value is one of these three names, and then log in as "----------". By logging in it will try to change the SessionVar and reset the cookie. Session var will change value, but the cookie won't, it will still be one of Anton, Trepi, or Antonio.

Hope this helps.

Thanks,

Anton

--
--
Lift, the simply functional web framework: http://liftweb.net
Code: http://github.com/lift
Discussion: http://groups.google.com/group/liftweb
Stuck? Help us help you: https://www.assembla.com/wiki/show/liftweb/Posting_example_code
 
---
You received this message because you are subscribed to a topic in the Google Groups "Lift" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/liftweb/zqlmY7M1cos/unsubscribe.
To unsubscribe from this group and all its topics, send an email to liftweb+u...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

[Antonio Salazar Cardozo]

Ok, rock on. I will look at this tonight.

Thanks,

Antonio

[Antonio Salazar Cardozo]

I'm not sure this is demonstrating the issue you think it's demonstrating.

Because the session becomes invalid, the login form submission doesn't actually have any of its fields bound on the server. This is why the logs have messages like this:

22:36:48.093 [qtp783121164-127 - /?F1379309587207A2OUPX=true&F1379309587205D4SOTH=----------&F1379309687206AYCL1G=] WARN  net.liftweb.http.LiftRules - Unmapped Lift-like parameter seen in request [/]: F1379309587207A2OUPX

22:36:48.098 [qtp783121164-127 - /?F1379309587207A2OUPX=true&F1379309587205D4SOTH=----------&F1379309687206AYCL1G=] WARN  net.liftweb.http.LiftRules - Unmapped Lift-like parameter seen in request [/]: F1379309587205D4SOTH

22:36:48.099 [qtp783121164-127 - /?F1379309587207A2OUPX=true&F1379309587205D4SOTH=----------&F1379309687206AYCL1G=] WARN  net.liftweb.http.LiftRules - Unmapped Lift-like parameter seen in request [/]: F1379309687206AYCL1G

(Side note: adding this logging is probably the most useful contribution I've made in two years for tracking down unexpected session-related bugs.)

The end result is that, when the session is no longer valid, the login form processor doesn't run, thus the login never occurs and the SessionVar is only set by the earlyInStateful test, which doesn't try to delete the cookie because it's found the appropriate user.

If I've misunderstood what's going on, please let me know. In particular, I wasn't 100% clear on what you expected to see happen, vs what was actually happening.

Thanks!

Antonio

PS: It's possible this is actually the problem that Trepi (heh) described. If so, the proper solution is to bind the login form a little more traditionally using stable field names and a specific URL that has a dispatch function associated with it looking for the stable S.params.

On Tuesday, January 14, 2014 12:47:54 PM UTC-5, Anton Khodakivskiy wrote:

[Anton Khodakivskiy]

Hi Antonio,

Perhaps my example was not very clear. I just have updated the repo, I think now it should be more transparent. There is a form that on submission calls ExtSession.setData to change SessionVar and Cookie values. The same method is called from earlyInStateful in case SessionVar has not been set, but the cookie is present (server restart or delete JSESSIONID). In the former case both SessionVar and Cookie values change properly, in the latter case only SessionVar changes value, and the Cookie is not updated. And now the the Trepi's catch: If you comment the line that changes the session var (ExtSession.scala:20), then Cookie will change value when set from earlyInStateful.

The resume - if SessionVar has been updated from earlyInStateful then the cookie won't be updated.

Does this make more sense?

[Antonio Salazar Cardozo]

Aha. I'll have a second look this evening armed with this info and report back :)

Thanks,

Antonio

[Trepi Dacious]

Hi All,

Many thanks to Anton for making the example project - it's a much clearer demonstration of the problem than I'd produced.

I've tried the example project and it does exactly demonstrate the problem I had - just setting the SessionVar seems to stop the cookie being set.

I made some modifications to the code to try some other options:

1. If you add some logging to testCookieEarlyInStateful, you can see that the first time we request "/" after a restart or delete of JSESSIONID, the early method runs twice. Otherwise it only runs once. This seems odd, and may well have an effect on the behaviour we're seeing. Using an S.notice also shows this, e.g. 
   
   

         S.notice("early before setData, cookie " + currentCookie + ", data " + currentData)

2. If you change the code to just set the cookie and session vars to the current time, a couple of things are apparent:
   
   

         val time = System.currentTimeMillis().toString

         S.notice("early at " + time + " before setData, cookie " + currentCookie + ", data " + currentData)

         setData(time)

   Firstly, it seems like S.addCookie doesn't update the value of the cookie that is seen by S.findCookie later in the request processing. So if you just keep refreshing "/", you can see that the "Cookie value:" in the snippet is always one update behind the session var - it shows the value of the cookie received from the browser even if a new cookie will be set by the response. I guess this one probably is deliberate, but it confused me a little at first.
   Secondly, and more importantly for this issue, the setData in this case manages to set both the SessionVar and the Cookie. We are still doing the same operations - reading both the SessionVar and the cookie, then writing both of them, but this time it works.

I think this possibly indicates the approximate cause of the error - something along these lines:

1. Delete JSESSIONID
2. Get "/"
3. earlyInStateful runs for the first time, notices empty SessionVar, sets the session var and produces a cookie in the response.
4. earlyInStateful runs for the second time, notices that the SessionVar is full, does nothing.
5. Response sent to browser

 My guess is that the cookie deletes/adds generated in step 3 are overridden by the lack of deletes/adds in step 4. E.g. maybe the cookie responses are cleared between step 3 and 4? Unfortunately I don't know enough about the details of the response processing to confirm this.

The weird thing is that the S.notices obviously don't get lost in the same way - we still see a notice for each of the earlyInStateful calls, which seems odd.

Hopefully this helps narrow things down - at the very least I'd be interested to find out why earlyInStateful runs twice :)

Thanks,

Ben

[Trepi Dacious]

Sorry for the extra message - just to clarify, when I said:

"Secondly, and more importantly for this issue, the setData in this case manages to set both the SessionVar and the Cookie."

I mean that the SessionVar and cookie are both set even when the JSESSIONID has just been deleted, so that the original code would fail.

[Antonio Salazar Cardozo]

Okay, I've found the issue. The SessionMaster inits the S context in order to start the session. This, it turns out, runs earlyInStateful. Now, cookies are set up internally by S until the init block ends, which in SessionMaster is just after all session setup stuff is executed. Then all cookie data is lost. However, SessionVar data is of course external to S's internal state, and lasts for the duration of the session. So, as you observed, earlyInStateful runs twice, the cookie is set the first time, but the second time that info has been lost AND the SessionVar is now properly set up.

At a glance, it seems like the way to deal with this will be to change _responseCookies in S from a ThreadGlobal to a TransientRequestVar. David, does that seem like a reasonable solution or is there a reason why ThreadGlobal is a better idea for _responseCookies?

Another, more invasive solution would be to change the LiftSession bootstrapping process to move the initialization of the session out of SessionMaster and into the LiftServlet S block, so that there's only one S.init happening and therefore the ThreadGlobals preserve their value throughout. This also carries the upside of only running earlyInStateful once in situations where the session has been lost.

Thoughts?

Thanks,

Antonio

[Trepi Dacious]

Thanks for finding that - I can't contribute much about the detailed implementation in terms of the Lift internals, but from my point of view it would seem to be better to have earlyInStateful only called once, since this is what I initially expected, and could possibly prevent other unexpected side effects?

From the point of view of just getting the extended session code to work, I think any change that allowed the cookies produced by the first earlyInStateful call to survive would be fine. 

I was wondering whether there is any workaround possible for now, for example by detecting which earlyInStateful call we are in, so that the first one can be ignored? I think this would allow my session code to work. I'm still not quite sure why the build in extended session in Lift works, it must have a slightly different logic, although it looks very similar.

[Antonio Salazar Cardozo]

Yeah… I'm not actually sure how the Lift one works. I'm a little short on time, but I haven't seen a good way to do a workaround. If someone can update the above example to use the ProtoExtendedSession stuff, I might be able to look into it and see how it's working (I haven't really used mapper at all, unfortunately).

Thanks,

Antonio

[Antonio Salazar Cardozo]

I take that back, there is a way you could handle this in the meantime. Add a session setup handler:

LiftSession.onSetupSession ::= { _: LiftSession =>

  mySessionVar.remove

}

This should clear the session var that's storing your session state after the earlyInStateful happens but before the second time it runs. This means you'll be in a clean state when you run earlyInStateful with the ability to set cookies.

Let me know if that works.

Thanks,

Antonio

[Trepi Dacious]

Ah that's great - I didn't know about LiftSession.onSetupSession

I followed your suggested approach with a slight modification: I think that clearing the var would work, but I thought it might be neater to just completely ignore the initial call. Therefore I added a SessionVar[Boolean] called "sessionIsSetup", defaulting to false, and I set this to true in onSetupSession. Then I do nothing in earlyInStateful until sessionIsSetup is true. I think this should be ok? Otherwise the system ends up essentially logging a user in, back out again, then back in again :)

Many thanks for the help, as far as I can tell my ExtendedSessions are working great now, which makes development a lot easier if nothing else! I was getting sick of clicking the login button every time I restarted the server :)

Thanks,

Ben.

[Antonio Salazar Cardozo]

Yep, that's definitely another approach. Although you could just as easily set the boolean to true in earlyInStateful, and avoid the extra concept of onSetupSession. Basically just a very simple state machine ;)

Thanks,

Antonio