Hi again,
I'm starting to see some cases where our deployed app stops responding
to web requests, and from the thread dump I believe it's a concurrency
issue with the way we're tracking sessions. I can give a more complete
example of all of this if someone wants it, but from this part of a
thread dump it looks like a call to HttpSession.getAttribute(String)
is actually expiring a session and, thus, calling my session listener,
which causes a problem. Am guessing someone was in the process of
logging out when this happened, and I'd expect an IllegalState
exception in that case. But should my getAttribute() call actually
result in a listener being involved?
I can provide code, but here's the stack from the thread dump:
"http-thread-pool-443(5)" daemon prio=10 tid=0x00002aaab80a1800
nid=0x1ebb waiting on condition [0x0000000042a51000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000703c9fd50> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:842)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1178)
at java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:807)
at [bobby's code].LoginStore.removeSession(LoginStore.java:64)
at [bobby's
code].SessionListener.sessionDestroyed(SessionListener.java:40)
at org.apache.catalina.session.StandardSession.expire(StandardSession.java:807)
- locked <0x00000007071203c8> (a
org.apache.catalina.session.StandardSession)
at org.apache.catalina.session.StandardSession.expire(StandardSession.java:769)
at org.apache.catalina.session.StandardSession.isValid(StandardSession.java:686)
at org.apache.catalina.session.StandardSession.getAttribute(StandardSession.java:1225)
at org.apache.catalina.session.StandardSessionFacade.getAttribute(StandardSessionFacade.java:152)
at [code to pull object out of session ... much code removed here]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:770)
at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1542)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:281)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:655)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:595)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:161)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:331)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:231)
at com.sun.enterprise.v3.services.impl.ContainerMapper$AdapterCallable.call(ContainerMapper.java:317)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:195)
at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:849)
at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:746)
at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1045)
at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:228)
at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:137)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:104)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:90)
at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:79)
at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:54)
at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:59)
at com.sun.grizzly.ContextTask.run(ContextTask.java:71)
at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:532)
at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:513)
at java.lang.Thread.run(Thread.java:662)
Locked ownable synchronizers:
- <0x0000000709a5d638> (a
java.util.concurrent.locks.ReentrantLock$NonfairSync)
I don't know where the correct version of the sources are for
org.apache.catalina.session.StandardSession, or else I'd try to sort
this myself. But why would my 'get' call end up expiring the session
and calling my listener?
As I said, I can provide a more full code example. But it's pretty
simple: using a ReentrantReadWriteLock am synching with a write lock
on storing/removing session objects from a Set, and during a read lock
am iterating over the Set of sessions and am calling getAttribute().
That call is somehow executing my session listener in the same thread,
which then tries to remove the session from my set and is blocking on
the write lock since a thread with a read lock can't acquire the write
one (though the reverse would work of course). Or maybe I'm reading
the above incorrectly. I think I can fix all this by simply not using
a read/write lock at all, but want to know if it's a bug that calling
getAttribute() results in a sessionDestroyed() call on my listener.
Thanks,
Bobby