and what we see are the failure emails that are sent at the bottom of the method, so we must have gotten an exception each time we tried the operation. We only report the last one, but they’re always the same thing. We get the same sorts of failures (at a lower frequency) from upset calls.

Our code is deployed in Glassfish and it’s single threaded, so the Couchbase operations happen on the main thread. Certainly I don’t know of anything we are doing that is interrupting the thread. Each of our sessions is a series of synchronous calls to our Thrift-based servers, so only one server instance accesses a particular bucket at any one time.

Here is a typical stack trace:

java.lang.RuntimeException: Interrupted while waiting for subscription to complete.
at com.couchbase.client.java.util.Blocking.blockForSingle(Blocking.java:79)
at com.couchbase.client.java.CouchbaseBucket.getAndTouch(CouchbaseBucket.java:299)
at com.couchbase.client.java.CouchbaseBucket.getAndTouch(CouchbaseBucket.java:294)
at com.paceap.eden.jpa.support.CacheOperations.getValue(CacheOperations.java:182)
at com.paceap.eden.session.SessionManager.getSession(SessionManager.java:214)
at sun.reflect.GeneratedMethodAccessor220.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1052)
at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1124)
at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:5388)
at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:619)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:800)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:571)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doAround(SystemInterceptorProxy.java:162)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:144)
at sun.reflect.GeneratedMethodAccessor166.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:861)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:800)
at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:370)
at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:5360)
at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:5348)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:214)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:89)
at com.sun.proxy.$Proxy206.getSession(Unknown Source)
at com.paceap.eden.session.EJB31_Generated__SessionManager__Intf____Bean.getSession(Unknown Source)
at com.paceap.eden.support.ActivationUtilities.validateSession(ActivationUtilities.java:1515)
at com.paceap.eden.activation.AccountOperations.getLibraryWithFilters(AccountOperations.java:664)
at com.paceap.eden.activation.ActivationHandler.getLibraryWithFilters(ActivationHandler.java:1756)
at sun.reflect.GeneratedMethodAccessor325.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1052)
at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1124)
at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:5388)
at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:619)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:800)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:571)
at com.paceap.eden.ejb.TXRetryCommitInterceptor.manageTransaction(TXRetryCommitInterceptor.java:64)
at sun.reflect.GeneratedMethodAccessor266.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:861)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:800)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:571)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doAround(SystemInterceptorProxy.java:162)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:144)
at sun.reflect.GeneratedMethodAccessor166.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:861)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:800)
at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:370)
at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:5360)
at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:5348)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:214)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:89)
at com.sun.proxy.$Proxy189.getLibraryWithFilters(Unknown Source)
at com.paceap.eden.thrift.activate.backend.ActivationBackend$Processor$getLibraryWithFilters.process(ActivationBackend.java:5186)
at com.paceap.eden.thrift.activate.backend.ActivationBackend$Processor.process(ActivationBackend.java:4919)
at com.paceap.eden.servlets.ActivationServlet.doPost(ActivationServlet.java:186)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:770)
at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1550)
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:860)
at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:757)
at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:1056)
at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:229)
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:745)
Caused by: java.lang.InterruptedException
at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1325)
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:282)
at com.couchbase.client.java.util.Blocking.blockForSingle(Blocking.java:74)
… 88 more

I don’t see much of anything on this topic when I google for it, in particular I haven’t seen anyone who is using sync operations say they see it. That makes me think it must have something to do with our setup, but that’s about all I know at this point.

As it turns out, we are running Glassfish 3.1.2.2 and if I grep the logs for “GRIZZLY0023:” I find quite a few of them that correlate nicely in time with the failure emails we have received. Sadly, our logs don’t record the RuntumeException we are seeing, that only goes in the email, but I’m pretty sure this explains at least a subset of what we are seeing.

We will do the library replacement that is suggested and also look at the http timeouts and I’ll post again if we still see problems after that.