grails.plugin.databasesession.SessionProxyFilter#proxySession attempts to invalidate null session

Details

Type: Bug
Status: Closed
Priority: Major
Resolution: Fixed
Affects Version/s: Grails-Database-Session 1.1.2
Fix Version/s: Grails-Database-Session 1.2
Labels:
None
Environment:
java version "1.6.0_31"
Java(TM) SE Runtime Environment (build 1.6.0_31-b04-414-11M3626)
Java HotSpot(TM) 64-Bit Server VM (build 20.6-b01-414, mixed mode)

Grails version: 2.0.0

Description

ISSUE:

In grails.plugin.databasesession.SessionProxyFilter#proxySession when (create == true && sessionId == null), it follows the code path to the section commented by "session cookie but it's been invalidated or is too old" which is actually not the case because the session does not exist at all and cannot be invalidated. There are guards for (sessionId == null && !create) and (create == false) in the method, but nothing for the situation of (create == true && sessionId == null). This then blows up when it gets to grails.plugin.databasesession.PersistentSessionAttributeValue#deleteBySessionId because it fails the assertion that sessionId hasLength. See below for the complete stacktrace.

STEPS TO REPRODUCE:
1. Follow the Basic Tutorial for the Heroku plugin, which uses databasesession plugin:
http://grails-plugins.github.com/grails-heroku/docs/manual/guide/3%20Tutorials.html#3.1%20Basic%20Tutorial

2. Either deploy to Heroku as explained in the tutorial or start locally in test mode with `grails test run-app`

3. Create a Book or Author record, which sets `create` to true in the method. Watch for the stacktrace below in the logs.

STACKTRACE:

2-04-25T23:38:16+00:00 heroku[router]: GET strong-autumn-8392.herokuapp.com/static/images/skin/database_table.png dyno=web.1 queue=0 wait=0ms service=2ms status=200 bytes=7262012-04-25T23:38:31+00:00 app[web.1]: 2012-04-25 23:38:31,223 [qtp1702714666-25 - /author/save] ERROR databasesession.GormPersisterService  - [Assertion failed] - this String argument must have length; it must not be null or empty2012-04-25T23:38:31+00:00 app[web.1]: java.lang.IllegalArgumentException: [Assertion failed] - this String argument must have length; it must not be null or empty2012-04-25T23:38:31+00:00 app[web.1]:
at grails.plugin.databasesession.PersistentSessionAttributeValue.deleteBySessionId(PersistentSessionAttributeValue.groovy:45)2012-04-25T23:38:31+00:00 app[web.1]:
at grails.plugin.databasesession.GormPersisterService.invalidate(GormPersisterService.groovy:111)2012-04-25T23:38:31+00:00 app[web.1]:
at grails.plugin.databasesession.SessionProxyFilter.proxySession(SessionProxyFilter.java:90)2012-04-25T23:38:31+00:00 app[web.1]:
at grails.plugin.databasesession.SessionProxyFilter$1.getSession(SessionProxyFilter.java:42)2012-04-25T23:38:31+00:00 app[web.1]:
at database.AuthorController.save(AuthorController.groovy:29)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:547)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1359)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:478)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:520)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:227)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:941)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:409)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:186)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:875)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:288)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.Dispatcher.forward(Dispatcher.java:115)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at grails.plugin.databasesession.SessionProxyFilter.doFilterInternal(SessionProxyFilter.java:51)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1330)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:478)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:520)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:227)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:941)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:409)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:186)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:875)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.Server.handle(Server.java:345)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:441)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.HttpConnection$RequestHandler.content(HttpConnection.java:936)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:801)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:224)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:51)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:586)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:44)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:598)2012-04-25T23:38:31+00:00 app[web.1]:
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:533)2012-04-25T23:38:31+00:00 app[web.1]:
at java.lang.Thread.run(Thread.java:636)2012-04-25T23:38:31+00:00 heroku[router]: POST strong-autumn-8392.herokuapp.com/author/save dyno=web.1 queue=0 wait=0ms service=524ms status=302 bytes=02012-04-25T23:38:32+00:00 heroku[router]: GET strong-autumn-8392.herokuapp.com/author/show/1 dyno=web.1 queue=0 wait=0ms service=992ms status=200 bytes=25032012-04-25T23:38:32+00:00 heroku[router]: GET strong-autumn-8392.herokuapp.com/static/images/skin/database_edit.png dyno=web.1 queue=0 wait=0ms service=4ms status=200 bytes=7672012-04-25T23:38:32+00:00 heroku[router]: GET strong-autumn-8392.herokuapp.com/static/images/skin/database_delete.png dyno=web.1 queue=0 wait=0ms service=7ms status=200 bytes=659

Activity

Ascending order - Click to sort in descending order

Hide

Permalink

Ryan Brainard added a comment - 14/Sep/12 3:12 PM - edited

Checking for an update on this issue. I have a user report that this has been fixed in fork https://github.com/RobertFischer/grails-database-session, so perhaps his changes could be merged in?

Show

Ryan Brainard added a comment - 14/Sep/12 3:12 PM - edited Checking for an update on this issue. I have a user report that this has been fixed in fork https://github.com/RobertFischer/grails-database-session , so perhaps his changes could be merged in?

Hide

Permalink

Andrew Garcia added a comment - 28/Sep/12 12:13 PM

I've patched this issue (I believe). I just need to create a fork and send Burt a pull request. Comment on that to come..

Show

Andrew Garcia added a comment - 28/Sep/12 12:13 PM I've patched this issue (I believe). I just need to create a fork and send Burt a pull request. Comment on that to come..

Hide

Permalink

Andrew Garcia added a comment - 28/Sep/12 3:30 PM

Thanks Ryan. Original report was from me..

I reverted to patching Burt's version of the plugin. I fixed the length Assertion on sessionID that was failing during invalidation, as well as a deserialization bug with spring security-core.

https://github.com/burtbeckwith/grails-database-session/pull/4

Thanks for the work on this plugin so far Burt. Much appreciated.

Show

Andrew Garcia added a comment - 28/Sep/12 3:30 PM Thanks Ryan. Original report was from me.. I reverted to patching Burt's version of the plugin. I fixed the length Assertion on sessionID that was failing during invalidation, as well as a deserialization bug with spring security-core. https://github.com/burtbeckwith/grails-database-session/pull/4 Thanks for the work on this plugin so far Burt. Much appreciated.

Hide

Permalink

Andrew Garcia added a comment - 28/Sep/12 11:57 PM

initial tests show stability of this plugin in heroku using 2-4 dynos (i didn't test more), with Grails 2.1.1 and Spring Security Core 1.2.7.2.

I did encounter an issue that I think was my fault with unique constraint failing on the primary key for the sessionattribute table. Maybe I polluted by hibernate_sequence/tables somehow....?

I was worried that it was a locking/race condition, but after create-dropping, I couldn't reproduce it...

Show

Andrew Garcia added a comment - 28/Sep/12 11:57 PM initial tests show stability of this plugin in heroku using 2-4 dynos (i didn't test more), with Grails 2.1.1 and Spring Security Core 1.2.7.2. I did encounter an issue that I think was my fault with unique constraint failing on the primary key for the sessionattribute table. Maybe I polluted by hibernate_sequence/tables somehow....? I was worried that it was a locking/race condition, but after create-dropping, I couldn't reproduce it...

Hide

Permalink

Burt Beckwith added a comment - 29/Sep/12 9:39 PM

Fixed by https://github.com/sronderos/grails-database-session/commit/71eb8af6099e2f94160d803d4faa15354727b656

Show

Burt Beckwith added a comment - 29/Sep/12 9:39 PM Fixed by https://github.com/sronderos/grails-database-session/commit/71eb8af6099e2f94160d803d4faa15354727b656

People

Assignee:

Burt Beckwith

Reporter:

Ryan Brainard

Vote (0)

Watch (3)

Dates

Created:

25/Apr/12 5:14 PM

Updated:

29/Sep/12 9:39 PM

Resolved:

29/Sep/12 9:39 PM

Agile

View on Board