Bug 900552 (JBPAPP6-1419)
| Summary: | Fix logging of "Standard expiration of session X failed; switching to a brute force cleanup. Problem is null" | ||
|---|---|---|---|
| Product: | [JBoss] JBoss Enterprise Application Platform 6 | Reporter: | Radoslav Husar <rhusar> |
| Component: | Clustering | Assignee: | Radoslav Husar <rhusar> |
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Jitka Kozana <jkudrnac> |
| Severity: | low | Docs Contact: | Russell Dickenson <rdickens> |
| Priority: | low | ||
| Version: | 6.0.0 | CC: | jkudrnac, kkhan, lthon, myarboro, rhusar, rjanik, rsvoboda |
| Target Milestone: | DR0 | ||
| Target Release: | EAP 6.3.0 | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| URL: | http://jira.jboss.org/jira/browse/JBPAPP6-1419 | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2014-06-28 15:26:33 UTC | Type: | Bug |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
| Embargoed: | |||
| Bug Depends On: | |||
| Bug Blocks: | 900611 | ||
Link: Added: This issue Cloned from AS7-4923 Workflow: Removed: GIT Pull Request workflow Added: jira Security: Added: Public Docs QE Status: Added: NEW Link: Added: This issue is incorporated by JBPAPP-7577 Link: Added: This issue is related to JBPAPP-9183 Link: Added: This issue is related to JBPAPP-9206 Release Notes Docs Status: Added: Not Yet Documented Link: Added: This issue is a dependency of JBPAPP-9290 Link: Removed: This issue is incorporated by JBPAPP-7577 Release Notes Text: Added: There is a known issue that produces the error: "Standard expiration of session X failed; switching to a brute force cleanup. Problem is null". This issue is still under investigation. Release Notes Docs Status: Removed: Not Yet Documented Added: Documented as Known Issue Release Notes Docs Status: Removed: Documented as Known Issue Release Notes Text: Removed: There is a known issue that produces the error: "Standard expiration of session X failed; switching to a brute force cleanup. Problem is null". This issue is still under investigation. Docs QE Status: Removed: NEW Also affects 6.1.0.ER1. Seen in https://jenkins.mw.lab.eng.bos.redhat.com/hudson/view/EAP6/view/EAP6-Clustering/view/EAP6-Failover/job/eap-6x-failover-http-session-jvmkill-dist-sync/38/console-perf18/ Saw this issue with 6.1.0.ER2: The session was created on perf20: perf20.log:[JBossINF] 21:38:07,903 INFO [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (ajp-perf20/10.16.90.58:8009-3) New session created: 7qjgksWDhd3oorwU20VQipvi.perf20 Perf20 21:48:51,663 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (Incoming-8,shared=udp) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Could not acquire lock on 7qjgksWDhd3oorwU20VQipvi on behalf of transaction GlobalTransaction:<perf19/web>:9434:remote. Lock is being held by null at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.newTimeoutException(AbstractTxLockingInterceptor.java:217) at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.waitForTransactionsToComplete(AbstractTxLockingInterceptor.java:210) at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:174) at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:123) at org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.lockAndRecord(OptimisticLockingInterceptor.java:254) at org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitSingleKeyCommand(OptimisticLockingInterceptor.java:249) at org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:242) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77) at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:335) at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:123) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) at org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) at org.infinispan.interceptors.TxInterceptor.invokeNextInterceptorAndVerifyTransaction(TxInterceptor.java:128) at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:115) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitPrepareCommand(TransactionSynchronizerInterceptor.java:58) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:216) at org.infinispan.statetransfer.StateTransferInterceptor.handleTxCommand(StateTransferInterceptor.java:189) at org.infinispan.statetransfer.StateTransferInterceptor.visitPrepareCommand(StateTransferInterceptor.java:93) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118) at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:119) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:101) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:122) at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:86) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220) at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484) at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391) at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249) at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:598) at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130) at org.jgroups.JChannel.up(JChannel.java:707) at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1020) at org.jgroups.protocols.RSVP.up(RSVP.java:188) at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) at org.jgroups.protocols.FlowControl.up(FlowControl.java:400) at org.jgroups.protocols.pbcast.GMS.up(GMS.java:896) at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245) at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:797) at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:420) at org.jgroups.protocols.pbcast.NAKACK2.up(NAKACK2.java:606) at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143) at org.jgroups.protocols.FD.up(FD.java:253) at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) at org.jgroups.protocols.MERGE3.up(MERGE3.java:290) at org.jgroups.protocols.Discovery.up(Discovery.java:359) at org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2616) at org.jgroups.protocols.TP.passMessageUp(TP.java:1263) at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1825) at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1798) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_38] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_38] at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_38] and finally: perf18: 21:52:25,361 WARN [org.jboss.as.web.session.DistributableSessionManager.clusterbench] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) JBAS018080: Standard expiration of session 7qjgksWDhd3oorwU20VQipvi failed; switching to a brute force cleanup. Problem is null Still seeing this in EAP 6.1.0.ER8. For example: https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-failover-http-session-shutdown-dist-sync/54/artifact/report/config/jboss-perf18/server.log https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-failover-http-session-undeploy-dist-sync/24/artifact/report/config/jboss-perf18/server.log https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-failover-http-session-jvmkill-dist-sync/43/artifact/report/config/jboss-perf18/server.log This log message will be obsolete in 6.3 as a result of the new web session clustering implementation. QA-ACKING since it is just logging fixes and I want to clear out as much as possible from the queue before going to bed @Kabir - thanks for joining QA side :) Agree with qa_ack. Verified for 6.3.0.DR0. |
project_key: JBPAPP6 I am seeing exception with missing reason {noformat} 19:54:12,862 WARN [org.apache.catalina.session.ManagerBase] (ContainerBackgroundProcessor[StandardEngine[jboss.web]]) JBAS018080: Standard expiration of session 7TYWbrkMf6UGi4WUu2Z3VUam failed; switching to a brute force cleanup. Problem is null {noformat} Looks like the actual exception is not well propagated to the message.