Fascinating - this is what I see:
[08/06/13 09:43:03:762 BST] 00000186 SimpleCookie 1
org.apache.shiro.web.servlet.SimpleCookie addCookieHeader Added
HttpServletResponse Cookie [JSESSIONID=deleteMe; Path=/Test-WAR;
Max-Age=0; Expires=Fri, 07-Jun-2013 08:43:03 GMT]
[08/06/13 09:43:03:762 BST] 00000186 SimpleCookie 3
org.apache.shiro.web.servlet.SimpleCookie removeFrom Removed
'JSESSIONID' cookie by setting maxAge=0
[08/06/13 09:43:03:793 BST] 00000186 AbstractValid 3
org.apache.shiro.session.mgt.AbstractValidatingSessionManager
doGetSession Attempting to retrieve session with key
org.apache.shiro.web.session.mgt.WebSessionKey@4f690448
[08/06/13 09:43:03:793 BST] 00000186 FaceletViewDe E Error Rendering
View[/app/index.xhtml]
java.lang.IllegalStateException:
If these log statements are a result of the same thread, then the
FaceletView (MyFaces) is trying to acquire a session after the Session
has been terminated.
Then, in the stack trace that follows:
at
org.apache.shiro.web.servlet.ShiroHttpSession.getAttribute(ShiroHttpSession.java:133)
at
org.apache.myfaces.context.servlet.SessionMap.getAttribute(SessionMap.java:50)
at
org.apache.myfaces.util.AbstractThreadSafeAttributeMap.put(AbstractThreadSafeAttributeMap.java:108)
at
org.apache.myfaces.util.AbstractThreadSafeAttributeMap.put(AbstractThreadSafeAttributeMap.java:38)
at
org.apache.myfaces.view.facelets.FaceletViewDeclarationLanguage.getResponseEncoding(FaceletViewDeclarationLanguage.java:1699)
at
org.apache.myfaces.view.facelets.FaceletViewDeclarationLanguage.createResponseWriter(FaceletViewDeclarationLanguage.java:1594)
at
org.apache.myfaces.view.facelets.FaceletViewDeclarationLanguage.renderView(FaceletViewDeclarationLanguage.java:1297)
at
org.apache.myfaces.application.ViewHandlerImpl.renderView(ViewHandlerImpl.java:263)
at
javax.faces.application.ViewHandlerWrapper.renderView(ViewHandlerWrapper.java:59)
at
javax.faces.application.ViewHandlerWrapper.renderView(ViewHandlerWrapper.java:59)
at
org.apache.myfaces.lifecycle.RenderResponseExecutor.execute(RenderResponseExecutor.java:85)
at
org.apache.myfaces.lifecycle.LifecycleImpl.render(LifecycleImpl.java:239)
at javax.faces.webapp.FacesServlet.service(FacesServlet.java:191)
It appears that MyFaces is trying to use the Session after it has been
closed - the renderView method calls AbstractThreadSafeAttributeMap
which in turn tries to use the Session. It is almost as if an HTTP
redirect is _not_ happening. Does Faces.redirect actually execute a
302 redirect? Or does it do something JSF-ish instead?
As to your question about Shiro's behavior vs your Servlet container's
behavior: Shiro's web support attempts to acquire a request's
referenced session at the beginning of a request chain (i.e. top of
the filter stack). If the session is expired or non-existent, then
the SessionException is ignored, with the expectation that a new
Session will be created later in the request if it is needed. This
effectively eliminates downstream code from worrying about
SessionExceptions.
However, Shiro currently does _not_ swallow these exceptions if the
Session is terminated and that same session is attempted to be used
again. Maybe a less intrusive behavior would be to only throw the
SessionException if the response hasn't yet been committed (because if
it had been committed, there wouldn't be a way to set the session ID
cookie, and the session couldn't be reliably referenced again,
indicating an error scenario).
But I wonder if this proposed behavior might be less ideal than
Shiro's current behavior: clearly you have logged out the user,
indicating the user is done using the application. Doesn't it seem
odd to allow a new session to be created and populated with data if
that session will (probably) never be used again? Why should
infrastructure (MyFaces) be allowed to create new sessions when you've
indicated that the user is done using the app?
Current servlet containers that allow this behavior allow for
potentially very inefficient use of resources (many unused sessions
could be created, eating up session storage memory and/or disk).
I'm curious as to your thoughts and what you'd like to see though!
I do have a request that would help me greatly in trying to trace
things further though: would you be able to add the current thread ID
in the log message output? It is hard to see if this stuff is
happening in a single thread of execution or across two requests (i.e.
It is hard to see with the log output if: 1) all of this happens in a
single thread or 2) the first request calls logout and redirects, and
the second request attempts to use the stale session ID.
I hope that helps clarify what I think is going on - I look forward to
your feedback!
Cheers,
--
Les Hazlewood | @lhazlewood
CTO, Stormpath | http://stormpath.com | @goStormpath | 888.391.5282
On Sat, Jun 8, 2013 at 9:09 AM, Paul Holding <[email protected]> wrote:
> Hi Les
>
>
> Les Hazlewood-2 wrote
>> It is not possible for an exception to propagate past a catch clause
>> that you have defined without you detecting it - this means something
>> else (separate from your logout() call) is attempting to use a session
>> without you being aware of it.
>
> I've now stepped through most of the code being executed from the
> SecurityUtils.getSubject().logout() method onwards and it indeed seems that
> something else is going on. The submit method in the logout backing bean
> (shown below) completes successfully, so it seems that JSF is doing
> something after the logoff button has been presses and the method in the
> backing bean executed which is trying use the session.
>
> public String submit() {
> try {
> System.out.println("****Logging out****");
> SecurityUtils.getSubject().logout();
> } catch (IllegalStateException e) {
> System.out.println("Do nothing");
> } catch (UnknownSessionException e) {
> System.out.println("Do nothing");
> }
> Faces.redirect("login.xhtml");
> return null;
> }
>
>
> Les Hazlewood-2 wrote
>> I've seen this happen a few times in web apps, usually due to one of 2
>> cases:
>> the web request.
>>
>> 2) subject.logout() is called after the http response has already been
>> committed (body content is being rendered). Because of the way
>> cookies work, it is not possible to delete the session id cookie in
>> this case, so subsequent requests will have an invalid session id
>> cookie and cause this exception.
>
>
> Having looked at all the output generated in the server log, I've spotted
> the following two entries that occur after the
> "java.lang.IllegalStateException:
> org.apache.shiro.session.UnknownSessionException" exception is thrown which
> I think might be relevant.
>
> com.ibm.ws.webcontainer.srt.SRTServletResponse setStatus WARNING: Cannot set
> status. Response already committed.
> com.ibm.ws.webcontainer.srt.SRTServletResponse addHeader SRVE8094W: WARNING:
> Cannot set header. Response already committed.
>
> Note that the above log entries only occur when using Shiro managed
> sessions.
>
> What I really don't understand is why these issues does not occur when I
> allow the container to manage the session (i.e. remove sessionManager =
> org.apache.shiro.web.session.mgt.DefaultWebSessionManager from the shiro.ini
> file). I've been able to reproduce this problem on both WebSphere and
> GlassFish so it would seem unlikely that it is the application server
> causing the problem although I know they both use Tomcat for the servlet
> container.
>
> I'm really struggling to understand what's going on here and why it works
> with container managed sessions but not with Shiro managed sessions.
>
> Kind Regards
>
> Paul
>
>
>
> --
> View this message in context:
> http://shiro-user.582556.n2.nabble.com/UnknownSessionException-when-calling-logout-method-using-Shiro-s-built-in-session-management-tp7578804p7578827.html
> Sent from the Shiro User mailing list archive at Nabble.com.
