Bug 1017777

Summary: Close action for Channel failed to execute (resource may be left in an indeterminate state)
Product: [JBoss] JBoss Enterprise Application Platform 6 Reporter: Richard Janík <rjanik>
Component: RemotingAssignee: David M. Lloyd <david.lloyd>
Status: CLOSED EOL QA Contact: Michal Vinkler <mvinkler>
Severity: high Docs Contact:
Priority: unspecified    
Version: 6.2.0, 6.4.0CC: ochaloup, pkremens
Target Milestone: ---   
Target Release: EAP 6.4.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-08-19 12:46:44 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:
Attachments:
Description Flags
6.4.0.DR7 failure none

Description Richard Janík 2013-10-10 13:35:52 UTC
Description of problem:

EAP 6.2.0.ER5

After the test is done, when the servers are shut down for the last time, the closing of Remoting channel can fail. There are at least two possible exceptions that accompany it:

19:26:09,308 INFO  [org.jboss.ejb.client.remoting] (Remoting "config-based-ejb-client-endpoint" task-1) EJBCLIENT000016: Channel Channel ID 917d1844 (outbound) of Remoting connection 532714b3 to perf18/10.16.90.54:4447 can no longer process messages
19:26:09,335 ERROR [org.jboss.remoting.resource] (Remoting "config-based-ejb-client-endpoint" read-1) Close action for Channel ID 917d1844 (outbound) of Remoting connection 532714b3 to perf18/10.16.90.54:4447 failed to execute (resource may be left in an indeterminate state)
java.util.NoSuchElementException
	at org.jboss.remoting3.remote.IntIndexHashMap$EntryIterator.next(IntIndexHashMap.java:668)
	at org.jboss.remoting3.remote.RemoteConnectionChannel.closeMessages(RemoteConnectionChannel.java:522)
	at org.jboss.remoting3.remote.RemoteConnectionChannel.closeAction(RemoteConnectionChannel.java:514)
	at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeAsync(AbstractHandleableCloseable.java:359)
	at org.jboss.remoting3.remote.RemoteConnectionHandler.closeAllChannels(RemoteConnectionHandler.java:390)
	at org.jboss.remoting3.remote.RemoteConnectionHandler.receiveCloseRequest(RemoteConnectionHandler.java:212)
	at org.jboss.remoting3.remote.RemoteReadListener.handleEvent(RemoteReadListener.java:106)
	at org.jboss.remoting3.remote.RemoteReadListener.handleEvent(RemoteReadListener.java:45)
	at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:72)
	at org.xnio.channels.TranslatingSuspendableChannel.handleReadable(TranslatingSuspendableChannel.java:189)
	at org.xnio.channels.TranslatingSuspendableChannel$1.handleEvent(TranslatingSuspendableChannel.java:103)
	at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:72)
	at org.xnio.nio.NioHandle.run(NioHandle.java:90)
	at org.xnio.nio.WorkerThread.run(WorkerThread.java:187)

and

06:53:43,425 INFO  [org.jboss.ejb.client.remoting] (Remoting "config-based-ejb-client-endpoint" task-3) EJBCLIENT000016: Channel Channel ID 9e60d049 (outbound) of Remoting connection 2fb669a8 to perf18/10.16.90.54:4447 can no longer process messages
06:53:43,425 ERROR [org.jboss.remoting.resource] (Remoting "config-based-ejb-client-endpoint" read-1) Close action for Channel ID 9e60d049 (outbound) of Remoting connection 2fb669a8 to perf18/10.16.90.54:4447 failed to execute (resource may be left in an indeterminate state)
java.lang.NullPointerException
	at org.jboss.remoting3.remote.RemoteConnectionChannel.closeMessages(RemoteConnectionChannel.java:523)
	at org.jboss.remoting3.remote.RemoteConnectionChannel.closeAction(RemoteConnectionChannel.java:514)
	at org.jboss.remoting3.spi.AbstractHandleableCloseable.closeAsync(AbstractHandleableCloseable.java:359)
	at org.jboss.remoting3.remote.RemoteConnectionHandler.closeAllChannels(RemoteConnectionHandler.java:390)
	at org.jboss.remoting3.remote.RemoteConnectionHandler.receiveCloseRequest(RemoteConnectionHandler.java:212)
	at org.jboss.remoting3.remote.RemoteReadListener.handleEvent(RemoteReadListener.java:106)
	at org.jboss.remoting3.remote.RemoteReadListener.handleEvent(RemoteReadListener.java:45)
	at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:72)
	at org.xnio.channels.TranslatingSuspendableChannel.handleReadable(TranslatingSuspendableChannel.java:189)a
	at org.xnio.channels.TranslatingSuspendableChannel$1.handleEvent(TranslatingSuspendableChannel.java:103)
	at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:72)
	at org.xnio.nio.NioHandle.run(NioHandle.java:90)
	at org.xnio.nio.WorkerThread.run(WorkerThread.java:187)

Links to logs:
https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-failover-ejb-ejbstateless-jvmkill-repl-async/30/console-perf17/consoleText
https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-failover-ejb-ejbremote-jvmkill-dist-async/32/console-perf17/consoleText

Comment 1 David M. Lloyd 2013-11-05 21:12:33 UTC
Looks like a real bug, however is this serious enough to warrant a fix for 6.2?

Comment 4 Richard Janík 2014-10-29 12:28:41 UTC
A similar failure to close Remoting channel has presented itself in clean startup/shutdown tests with 6.4.0.DR7. Appeared after server started shutting down. Seen once out of ~120 runs.

Link: https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-manu-acceptance-multinode-startup-different-IPs-rhel/67/jdk=jdk1.8,label_exp=RHEL5%20&&%20x86%20&&%20!(vmg20-rhel5-x86%20%7C%7C%20vmg19-rhel5-x86)/artifact/manu-snapshot-1411718619526/bin/target/manu-reports/units/manu.testsuite.eap.eap6.acceptance.multinodestartup.MultinodeStartupDifferentIPs/server.log-standalone.xml-server2.log

Log is also in attachments.



03:03:29,032 ERROR [org.jboss.remoting.resource] (Remoting "node1:MANAGEMENT" task-7) Close action for Channel ID 60ecd1e3 (inbound) of Remoting connection 0046086c to /10.16.93.31:58635 failed to execute (resource may be left in an indeterminate state): java.util.concurrent.RejectedExecutionException: Task org.jboss.remoting3.remote.RemoteConnectionChannel$7@b8d3dc rejected from org.xnio.XnioWorker$TaskPool@1ba436f[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 7]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2047) [rt.jar:1.8.0_20]
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823) [rt.jar:1.8.0_20]
	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369) [rt.jar:1.8.0_20]
	at org.xnio.XnioWorker.execute(XnioWorker.java:572) [xnio-api-3.0.11.GA-redhat-2.jar:3.0.11.GA-redhat-2]
	at org.jboss.remoting3.remote.RemoteConnectionChannel.closeMessages(RemoteConnectionChannel.java:545) [jboss-remoting-3.3.3.Final-redhat-1.jar:3.3.3.Final-redhat-1]
	at org.jboss.remoting3.remote.RemoteConnectionChannel.closeAction(RemoteConnectionChannel.java:531) [jboss-remoting-3.3.3.Final-redhat-1.jar:3.3.3.Final-redhat-1]
	at org.jboss.remoting3.spi.AbstractHandleableCloseable.close(AbstractHandleableCloseable.java:153) [jboss-remoting-3.3.3.Final-redhat-1.jar:3.3.3.Final-redhat-1]
	at org.jboss.as.protocol.mgmt.ManagementChannelReceiver.handleEnd(ManagementChannelReceiver.java:129) [jboss-as-protocol-7.5.0.Final-redhat-9.jar:7.5.0.Final-redhat-9]
	at org.jboss.remoting3.remote.RemoteConnectionChannel$2.run(RemoteConnectionChannel.java:282) [jboss-remoting-3.3.3.Final-redhat-1.jar:3.3.3.Final-redhat-1]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_20]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_20]
	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_20]

03:03:29,052 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) Exception in thread "Remoting "node1:MANAGEMENT" task-7" java.lang.IllegalStateException: java.util.concurrent.RejectedExecutionException: Task org.jboss.remoting3.remote.RemoteConnectionChannel$7@b8d3dc rejected from org.xnio.XnioWorker$TaskPool@1ba436f[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 7]
03:03:29,053 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at org.jboss.remoting3.spi.AbstractHandleableCloseable.close(AbstractHandleableCloseable.java:171)
03:03:29,053 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at org.jboss.as.protocol.mgmt.ManagementChannelReceiver.handleEnd(ManagementChannelReceiver.java:129)
03:03:29,054 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at org.jboss.remoting3.remote.RemoteConnectionChannel$2.run(RemoteConnectionChannel.java:282)
03:03:29,055 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
03:03:29,055 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
03:03:29,056 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at java.lang.Thread.run(Thread.java:745)
03:03:29,056 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) Caused by: java.util.concurrent.RejectedExecutionException: Task org.jboss.remoting3.remote.RemoteConnectionChannel$7@b8d3dc rejected from org.xnio.XnioWorker$TaskPool@1ba436f[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 7]
03:03:29,057 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2047)
03:03:29,058 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823)
03:03:29,058 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369)
03:03:29,059 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at org.xnio.XnioWorker.execute(XnioWorker.java:572)
03:03:29,059 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at org.jboss.remoting3.remote.RemoteConnectionChannel.closeMessages(RemoteConnectionChannel.java:545)
03:03:29,060 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at org.jboss.remoting3.remote.RemoteConnectionChannel.closeAction(RemoteConnectionChannel.java:531)
03:03:29,061 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	at org.jboss.remoting3.spi.AbstractHandleableCloseable.close(AbstractHandleableCloseable.java:153)
03:03:29,062 ERROR [stderr] (Remoting "node1:MANAGEMENT" task-7) 	... 5 more

Comment 5 Richard Janík 2014-10-29 12:29:42 UTC
Created attachment 951761 [details]
6.4.0.DR7 failure

Comment 8 Richard Janík 2014-11-18 11:59:24 UTC
Seen again with 6.4.0.DR10. Configuration: oracle jdk 1.8, RHEL5 x86_64

Comment 9 Petr Kremensky 2014-12-05 07:32:16 UTC
We are seeing this also in other tests across whole certification matrix, however as Richard wrote, it is quite uncommon.