Bug 1030484

Summary: ejb-asynchronous quickstart : stacktrace in server log after client successful completion
Product: [JBoss] JBoss Enterprise Application Platform 6 Reporter: sgilda
Component: QuickstartsAssignee: sgilda
Status: CLOSED CURRENTRELEASE QA Contact: Nikoleta Hlavickova <nziakova>
Severity: medium Docs Contact: Russell Dickenson <rdickens>
Priority: unspecified    
Version: 6.2.0CC: bsutter, nziakova, pmuir, wfink
Target Milestone: CR2   
Target Release: EAP 6.2.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-12-15 16:49:19 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:

Description sgilda 2013-11-14 14:29:38 UTC
Description of problem:

ejb-asynchronous, After the client tests successfully complete there is an error in the server log. 

To reproduce:

1. Build and deploy the application using 'mvn clean install jboss-as:deploy'
2. Navigate to the client directory and run the client: 'mvn exec:exec'

In the client, you see the Info messages and get BUILD success.
In the server log, you see all the correct messages, ending with this: 
09:19:08,263 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 1) action 'fireAndForget' finished

About 5 or more seconds after the tests complete, you see this in the server log: 

ERROR [org.jboss.as.ejb3] (EJB default - 1) JBAS014249: Error invoking method public abstract void org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccess.fireAndForget(long) on bean named AsynchronousAccessBean for appname  modulename jboss-ejb-asynchronous-ejb distinctname : java.lang.NullPointerException
	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:322)
	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:70)
	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:203)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_09]
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) [rt.jar:1.7.0_09]
	at java.util.concurrent.FutureTask.run(FutureTask.java:166) [rt.jar:1.7.0_09]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) [rt.jar:1.7.0_09]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) [rt.jar:1.7.0_09]
	at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_09]
	at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final-redhat-1.jar:2.1.1.Final-redhat-1]

08:46:12,776 ERROR [org.jboss.as.ejb3] (EJB default - 1) JBAS014250: Could not write method invocation failure for method public abstract void org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccess.fireAndForget(long) on bean named AsynchronousAccessBean for appname  modulename jboss-ejb-asynchronous-ejb distinctname  due to: java.io.IOException: JBAS014560: Could not open message outputstream for writing to Channel
	at org.jboss.as.ejb3.remote.protocol.AbstractMessageHandler.writeException(AbstractMessageHandler.java:102)
	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$400(MethodInvocationMessageHandler.java:70)
	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:213)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_09]
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) [rt.jar:1.7.0_09]
	at java.util.concurrent.FutureTask.run(FutureTask.java:166) [rt.jar:1.7.0_09]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) [rt.jar:1.7.0_09]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) [rt.jar:1.7.0_09]
	at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_09]
	at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final-redhat-1.jar:2.1.1.Final-redhat-1]
Caused by: org.jboss.remoting3.NotOpenException: Writes closed
	at org.jboss.remoting3.remote.RemoteConnectionChannel.openOutboundMessage(RemoteConnectionChannel.java:108) [jboss-remoting-3.2.17.GA-redhat-1.jar:3.2.17.GA-redhat-1]
	at org.jboss.remoting3.remote.RemoteConnectionChannel.writeMessage(RemoteConnectionChannel.java:297) [jboss-remoting-3.2.17.GA-redhat-1.jar:3.2.17.GA-redhat-1]
	at org.jboss.as.ejb3.remote.protocol.versionone.ChannelAssociation.acquireChannelMessageOutputStream(ChannelAssociation.java:68)
	at org.jboss.as.ejb3.remote.protocol.AbstractMessageHandler.writeException(AbstractMessageHandler.java:100)
	... 9 more
Version-Release number of selected component (if applicable):


How reproducible:


Steps to Reproduce:
1.
2.
3.

Actual results:


Expected results:


Additional info:

Comment 1 sgilda 2013-11-14 14:37:15 UTC
Adding entire server log:

09:18:53,261 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 2) Will wait for 200ms
09:18:53,261 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 1) 'fireAndForget' Will wait for 15000ms
09:18:53,462 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 2) returning the result
09:18:53,682 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 3) Will wait for 1500ms
09:18:55,182 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 3) returning the result
09:18:55,689 INFO  [org.jboss.ejb.client] (EJB default - 5) JBoss EJB Client version 1.0.23.Final-redhat-1
09:18:55,715 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 6) Will wait for 5000ms
09:18:55,716 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 7) Will wait for 3000ms
09:18:58,717 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 7) returning the result
09:19:00,716 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 6) returning the result
09:19:00,725 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 8) Will wait for 500ms
09:19:01,227 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 8) returning the result
09:19:01,228 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.ParallelAccessBean] (EJB default - 8) CALL result returning at Thu Nov 14 09:19:01 EST 2013, duration was 500ms
09:19:08,263 INFO  [org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccessBean] (EJB default - 1) action 'fireAndForget' finished
09:19:08,265 ERROR [org.jboss.as.ejb3] (EJB default - 1) JBAS014249: Error invoking method public abstract void org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccess.fireAndForget(long) on bean named AsynchronousAccessBean for appname  modulename jboss-ejb-asynchronous-ejb distinctname : java.lang.NullPointerException
	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:322)
	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:70)
	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:203)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_09]
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) [rt.jar:1.7.0_09]
	at java.util.concurrent.FutureTask.run(FutureTask.java:166) [rt.jar:1.7.0_09]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) [rt.jar:1.7.0_09]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) [rt.jar:1.7.0_09]
	at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_09]
	at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final-redhat-1.jar:2.1.1.Final-redhat-1]

09:19:08,269 ERROR [org.jboss.as.ejb3] (EJB default - 1) JBAS014250: Could not write method invocation failure for method public abstract void org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccess.fireAndForget(long) on bean named AsynchronousAccessBean for appname  modulename jboss-ejb-asynchronous-ejb distinctname  due to: java.io.IOException: JBAS014560: Could not open message outputstream for writing to Channel
	at org.jboss.as.ejb3.remote.protocol.AbstractMessageHandler.writeException(AbstractMessageHandler.java:102)
	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$400(MethodInvocationMessageHandler.java:70)
	at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:213)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [rt.jar:1.7.0_09]
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) [rt.jar:1.7.0_09]
	at java.util.concurrent.FutureTask.run(FutureTask.java:166) [rt.jar:1.7.0_09]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) [rt.jar:1.7.0_09]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) [rt.jar:1.7.0_09]
	at java.lang.Thread.run(Thread.java:722) [rt.jar:1.7.0_09]
	at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.1.1.Final-redhat-1.jar:2.1.1.Final-redhat-1]
Caused by: org.jboss.remoting3.NotOpenException: Writes closed
	at org.jboss.remoting3.remote.RemoteConnectionChannel.openOutboundMessage(RemoteConnectionChannel.java:108) [jboss-remoting-3.2.17.GA-redhat-1.jar:3.2.17.GA-redhat-1]
	at org.jboss.remoting3.remote.RemoteConnectionChannel.writeMessage(RemoteConnectionChannel.java:297) [jboss-remoting-3.2.17.GA-redhat-1.jar:3.2.17.GA-redhat-1]
	at org.jboss.as.ejb3.remote.protocol.versionone.ChannelAssociation.acquireChannelMessageOutputStream(ChannelAssociation.java:68)
	at org.jboss.as.ejb3.remote.protocol.AbstractMessageHandler.writeException(AbstractMessageHandler.java:100)
	... 9 more

Comment 2 sgilda 2013-11-14 14:47:11 UTC
The README states that there is a bug in AS 7.1.1 Final that an error will be logged that the result can not be written. It appears this is still the case with EAP 6.2.

I want to verify this with Wolf and will modify the README with the correct information.

Comment 4 sgilda 2013-11-15 13:07:24 UTC
Modified the note to update the server release and make it more obvious. Changed it to:

_NOTE: In EAP 6.2, you may see the following errors in the server log after the client tests successfully complete. This is due to an issue with the server opening the outputstream and you can ignore the errors._

        JBAS014249: Error invoking method public abstract void org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccess.fireAndForget(long) on bean named AsynchronousAccessBean for appname  modulename jboss-ejb-asynchronous-ejb distinctname : java.lang.NullPointerException
        
        JBAS014250: Could not write method invocation failure for method public abstract void org.jboss.as.quickstarts.ejb.asynchronous.AsynchronousAccess.fireAndForget(long) on bean named AsynchronousAccessBean for appname  modulename jboss-ejb-asynchronous-ejb distinctname  due to: java.io.IOException: JBAS014560: Could not open message outputstream for writing to Channel

Comment 5 Nikoleta Hlavickova 2013-11-26 11:39:46 UTC
Verified for EAP 6.2.0 CR3.