[jboss-user] [JBoss Cache] - Error writing security data to cache: Unable to acquire lock on Fqn

Steve Dempsey [https://community.jboss.org/people/steve_slhs] created the discussion "Error writing security data to cache: Unable to acquire lock on Fqn" To view the discussion, visit: https://community.jboss.org/message/789840#789840 -------------------------------------------------------------- We upgraded our third party application.  There is a single web server front end for one population of users and a fat client for another set.  They connect to an MS –SQL 2008 R2 server (not clustered).  We have been seeing chronic issues happening throughout a given day for the users, resulting in loss of data for a given screen they are on.  We are not seeing any issues on LAN/WAN and the server resources (CPU/MEM/Disk –I/O are not taxed). Errors are completely random. We are not seeing any errors on the SQL server logs that correspond to the error on the web server.  We have rebuilt the Web server from scratch with the same outcome. Errors are completely random. *Here is the end-user error message:* Error writing security data to cache: Error writing cache. branch:/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774 name: BLUE01 [Unable to acquire lock on Fqn [/appname-cache/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774] after [10000] milliseconds for requestor [GlobalTransaction:<null>:7352]! Lock held by [GlobalTransaction:<null>:7349]]] *Application log extract:* <argumentsSet>   <arguments>     <uuid>80E47838-756E-4C1E-93BB-1B50A6CDB274</uuid>     <caseNo>1532402</caseNo>     <resourceId>119585</resourceId>     <resourceType>INVENTORY</resourceType>     <quantity>1</quantity>   </arguments> </argumentsSet> ================================================================================ 2013-01-08 08:29:05,144 [http-0.0.0.0-8080-22] 41332426 INFO  [com.vendor.appname.service.postcase.usage.materialusage.PersistedUsageItemMaterialUsageBean] (http-0.0.0.0-8080-22:) Finished updating material usage for persisted item 2013-01-08 08:29:06,019 [http-0.0.0.0-8080-10] 41333301 ERROR [org.jboss.aspects.tx.TxPolicy] (http-0.0.0.0-8080-10:) javax.ejb.EJBTransactionRolledbackException: Error writing security data to cache: Error writing cache. branch:/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774 name:BLUE01 [Unable to acquire lock on Fqn [/appname-cache/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774] after [10000] milliseconds for requestor [GlobalTransaction:<null>:7352]! Lock held by [GlobalTransaction:<null>:7349]] 2013-01-08 08:29:06,019 [http-0.0.0.0-8080-10] 41333301 ERROR [org.jboss.aspects.tx.TxPolicy] (http-0.0.0.0-8080-10:) javax.ejb.EJBTransactionRolledbackException: Error writing security data to cache: Error writing cache. branch:/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774 name:BLUE01 [Unable to acquire lock on Fqn [/appname-cache/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774] after [10000] milliseconds for requestor [GlobalTransaction:<null>:7352]! Lock held by [GlobalTransaction:<null>:7349]] 2013-01-08 08:29:06,035 [http-0.0.0.0-8080-10] 41333317 ERROR [org.jboss.aspects.tx.TxPolicy] (http-0.0.0.0-8080-10:) javax.ejb.EJBTransactionRolledbackException: Error writing security data to cache: Error writing cache. branch:/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774 name:BLUE01 [Unable to acquire lock on Fqn [/appname-cache/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774] after [10000] milliseconds for requestor [GlobalTransaction:<null>:7352]! Lock held by [GlobalTransaction:<null>:7349]] 2013-01-08 08:29:06,035 [http-0.0.0.0-8080-10] 41333317 ERROR [com.vendor.appname.service.command.BufferedCommandProcessor] (http-0.0.0.0-8080-10:) Error caught, rolling back transaction. 2013-01-08 08:29:06,035 [http-0.0.0.0-8080-10] 41333317 ERROR [com.vendor.appname.service.command.BufferedCommandProcessor] (http-0.0.0.0-8080-10:) This is the root error message: Error writing security data to cache: Error writing cache. branch:/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774 name:BLUE01 [Unable to acquire lock on Fqn [/appname-cache/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774] after [10000] milliseconds for requestor [GlobalTransaction:<null>:7352]! Lock held by [GlobalTransaction:<null>:7349]] 2013-01-08 08:29:06,331 [http-0.0.0.0-8080-3] 41333613 INFO  [com.vendor.appname.service.command.BufferedCommandProcessor] (http-0.0.0.0-8080-3:) [ 11005475 ] Responding to addCommand. = *Web server log extract* 2013-01-08 08:29:06,019 ERROR [org.jboss.aspects.tx.TxPolicy] (http-0.0.0.0-8080-10) javax.ejb.EJBTransactionRolledbackException: Error writing security data to cache: Error writing cache. branch:/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774 name:BLUE01 [Unable to acquire lock on Fqn [/appname-cache/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774] after [10000] milliseconds for requestor [GlobalTransaction:<null>:7352]! Lock held by [GlobalTransaction:<null>:7349]] 2013-01-08 08:29:06,019 ERROR [org.jboss.aspects.tx.TxPolicy] (http-0.0.0.0-8080-10) javax.ejb.EJBTransactionRolledbackException: Error writing security data to cache: Error writing cache. branch:/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774 name:BLUE01 [Unable to acquire lock on Fqn [/appname-cache/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774] after [10000] milliseconds for requestor [GlobalTransaction:<null>:7352]! Lock held by [GlobalTransaction:<null>:7349]] 2013-01-08 08:29:06,035 ERROR [org.jboss.aspects.tx.TxPolicy] (http-0.0.0.0-8080-10) javax.ejb.EJBTransactionRolledbackException: Error writing security data to cache: Error writing cache. branch:/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774 name:BLUE01 [Unable to acquire lock on Fqn [/appname-cache/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774] after [10000] milliseconds for requestor [GlobalTransaction:<null>:7352]! Lock held by [GlobalTransaction:<null>:7349]] 2013-01-08 08:29:06,035 ERROR [com.vendor.appname.service.command.BufferedCommandProcessor] (http-0.0.0.0-8080-10) Error caught, rolling back transaction. 2013-01-08 08:29:06,035 ERROR [com.vendor.appname.service.command.BufferedCommandProcessor] (http-0.0.0.0-8080-10) This is the root error message: Error writing security data to cache: Error writing cache. branch:/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774 name:BLUE01 [Unable to acquire lock on Fqn [/appname-cache/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774] after [10000] milliseconds for requestor [GlobalTransaction:<null>:7352]! Lock held by [GlobalTransaction:<null>:7349]] 2013-01-08 08:29:06,097 WARN  [org.directwebremoting.impl.DefaultRemoter] (http-0.0.0.0-8080-10) Method execution failed: 1. com.vendor.appname.service.ServiceException: A system error prevented this transaction from being completed. Error writing security data to cache: Error writing cache. branch:/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774 name:BLUE01 [Unable to acquire lock on Fqn [/appname-cache/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774] after [10000] milliseconds for requestor [GlobalTransaction:<null>:7352]! Lock held by [GlobalTransaction:<null>:7349]]                 at com.vendor.appname.service.command.BufferedCommandProcessor.executeCommands(BufferedCommandProcessor.java:454)                 at sun.reflect.GeneratedMethodAccessor2764.invoke(Unknown Source)                 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)                 at java.lang.reflect.Method.invoke(Method.java:597)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeTarget(MethodInvocation.java:122)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111)                 at org.jboss.ejb3.EJBContainerInvocationWrapper.invokeNext(EJBContainerInvocationWrapper.java:69)                 at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.invoke(InterceptorSequencer.java:73)                 at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.aroundInvoke(InterceptorSequencer.java:59)                 at sun.reflect.GeneratedMethodAccessor321.invoke(Unknown Source)                 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)                 at java.lang.reflect.Method.invoke(Method.java:597)                 at org.jboss.aop.advice.PerJoinpointAdvice.invoke(PerJoinpointAdvice.java:174)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.fillMethod(InvocationContextInterceptor.java:72)                 at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_fillMethod_13902059.invoke(InvocationContextInterceptor_z_fillMethod_13902059.java)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.setup(InvocationContextInterceptor.java:88)                 at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_setup_13902059.invoke(InvocationContextInterceptor_z_setup_13902059.java)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:62)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.entity.ExtendedPersistenceContextPropagationInterceptor.invoke(ExtendedPersistenceContextPropagationInterceptor.java:60)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:56)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.stateful.StatefulInstanceInterceptor.invoke(StatefulInstanceInterceptor.java:81)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:79)                 at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:190)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:76)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.security.RunAsSecurityInterceptorv2.invoke(RunAsSecurityInterceptorv2.java:94)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.security.RoleBasedAuthorizationInterceptorv2.invoke(RoleBasedAuthorizationInterceptorv2.java:201)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.security.Ejb3AuthenticationInterceptorv2.invoke(Ejb3AuthenticationInterceptorv2.java:186)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:41)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.BlockContainerShutdownInterceptor.invoke(BlockContainerShutdownInterceptor.java:67)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.aspects.currentinvocation.CurrentInvocationInterceptor.invoke(CurrentInvocationInterceptor.java:67)                 at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)                 at org.jboss.ejb3.session.SessionSpecContainer.invoke(SessionSpecContainer.java:176)                 at org.jboss.ejb3.session.SessionSpecContainer.invoke(SessionSpecContainer.java:216)                 at org.jboss.ejb3.proxy.impl.handler.session.SessionProxyInvocationHandlerBase.invoke(SessionProxyInvocationHandlerBase.java:207)                 at org.jboss.ejb3.proxy.impl.handler.session.SessionProxyInvocationHandlerBase.invoke(SessionProxyInvocationHandlerBase.java:164)                 at $Proxy557.executeCommands(Unknown Source)                 at sun.reflect.GeneratedMethodAccessor6205.invoke(Unknown Source)                 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)                 at java.lang.reflect.Method.invoke(Method.java:597)                 at org.directwebremoting.impl.ExecuteAjaxFilter.doFilter(ExecuteAjaxFilter.java:34)                 at org.directwebremoting.impl.DefaultRemoter$1.doFilter(DefaultRemoter.java:428)                 at org.directwebremoting.impl.DefaultRemoter.execute(DefaultRemoter.java:431)                 at org.directwebremoting.impl.DefaultRemoter.execute(DefaultRemoter.java:274)                 at org.directwebremoting.servlet.PlainCallHandler.handle(PlainCallHandler.java:52)                 at org.directwebremoting.servlet.UrlProcessor.handle(UrlProcessor.java:101)                 at org.directwebremoting.servlet.DwrServlet.doPost(DwrServlet.java:120)                 at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)                 at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)                 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)                 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)                 at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)                 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)                 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)                 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)                 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)                 at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:190)                 at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:433)                 at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:92)                 at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)                 at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)                 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)                 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)                 at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158)                 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)                 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)                 at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:829)                 at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:598)                 at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)                 at java.lang.Thread.run(Thread.java:619) 2013-01-08 08:29:06,097 WARN  [org.directwebremoting.dwrp.BaseCallMarshaller] (http-0.0.0.0-8080-10) --Erroring: batchId[9] message[com.vendor.appname.service.ServiceException: A system error prevented this transaction from being completed. Error writing security data to cache: Error writing cache. branch:/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774 name:BLUE01 [Unable to acquire lock on Fqn [/appname-cache/appname-security/record/0EED5567-90FA-475A-B9DF-880B1C504774] after [10000] milliseconds for requestor [GlobalTransaction:<null>:7352]! Lock held by [GlobalTransaction:<null>:7349]]] 2013-01-08 08:29:06,331 INFO  [org.directwebremoting.impl.DefaultRemoter] (http-0.0.0.0-8080-3) Exec: BufferedCommandProcessorWrapper.addCommand() 2013-01-08 08:29:06,331 INFO  [com.vendor.appname.service.command.BufferedCommandProcessor] (http-0.0.0.0-8080-3) [ 11005475 ] Responding to addCommand. *Any help would be appreciated! Thanks!* -------------------------------------------------------------- Reply to this message by going to Community [https://community.jboss.org/message/789840#789840] Start a new discussion in JBoss Cache at Community [https://community.jboss.org/choose-container!input.jspa?contentType=1&...]