CORBA_BAD_INV_ORDER running AS 5 IIOP tests with JDK 6

[shelly.mcgowan]

There are some iiop test failures seen running the AS 5 testsuite with JDK 6 (hot topic these days). The exceptions occur during InputStream or OutputStream operations within the invoke() method in:
./iiop/src/main/org/jboss/proxy/ejb/DynamicIIOPStub.java

The nested exception is org.omg.CORBA.BAD_INV_ORDER
Caused by: org.omg.CORBA.BAD_INV_ORDER: vmcid: 0x0 minor code: 4 completed: No
at org.jacorb.orb.ORB.work_pending(Unknown Source)
at org.jacorb.orb.Delegate.checkORB(Unknown Source)
at org.jacorb.orb.Delegate.invoke_internal(Unknown Source)
at org.jacorb.orb.Delegate.invoke(Unknown Source)
at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:457)
at org.jboss.proxy.ejb.DynamicIIOPStub.invoke(DynamicIIOPStub.java:124)

The class imports:
import org.omg.CORBA_2_3.portable.InputStream;
import org.omg.CORBA_2_3.portable.OutputStream;

These classes are in jacorb.jar and in jre/lib/rt.jar of JDK 6 . Looking for suggestions on how to reconcile running in this configuration. Seems more than just a test config issue.

[sguilhen]

This is a strange error, because the BAD_INV_ORDER with minor code 4 is usually thrown when code attempts to invoke a method after the ORB has shut down. This error usually describes operations being executed in the wrong order, like invoking methods on a stub before initializing the ORB, or after the ORB has shut down.

Is it easy to reproduce the errors you are seeing? If so, and if you provide me a testcase that is failing I can take a look at it later.

[shelly.mcgowan]

Using JavaSE 6,

start the 'all' server configuration

cd $JBOSS_HOME/testsuite
./build.sh tests-iiop

The failures are seen in:
org.jboss.test.bankiiop.test.BankStressTestCase
org.jboss.test.iiop.test.ParameterPassingStressTestCase
org.jboss.test.marshalliiop.test.EjbUnMarshalUnitTestCase

[jeffzhang]

I had tested both JDK5 and JDK6 and mix them.
AS Server Tests
JDK5 JDK5 PASS
JDK6 JDK6 FAIL
JDK5 JDK6 FAIL
JDK6 JDK5 PASS

So JDK6/JacORB client failed the tests.


There are log information in test.log:
=================
2008-04-22 21:20:23,546 DEBUG [jacorb.orb.giop] ClientConnectionManager: cannot release ClientGIOPConnection to 127.0.0.1:3528 (115d06c) (still has 1 client(s))
2008-04-22 21:20:23,546 DEBUG [jacorb.orb.delegate] Delegate released!
2008-04-22 21:20:23,546 INFO [jacorb.orb] prepare ORB for shutdown...
2008-04-22 21:20:23,546 INFO [jacorb.orb] ORB going down...
2008-04-22 21:20:23,546 DEBUG [jacorb.orb.giop.conn] GIOPConnectionManager.shutdown(), 0 connections
2008-04-22 21:20:23,546 DEBUG [jacorb.giop.conn] ClientGIOPConnection to 127.0.0.1:3528 (115d06c): close()
==================

Please see the log "prepare ORB for shutdown..."
If we use JDK5, we can't find the same information in the log file.
Some code call the shutdown() somewhere.

[jeffzhang]

I add the throwable.printStaceTrace in the JacORB source code ORB.shutdown():
public void shutdown( boolean wait_for_completion )
{
if(logger.isInfoEnabled())
{
logger.info("prepare ORB for shutdown...");
Throwable ex = new Throwable("shutdown");
ex.printStackTrace();

}

Then I get the log information:
[junit] java.lang.Throwable: shutdown
[junit] at org.jacorb.orb.ORB.shutdown(ORB.java:1772)
[junit] at org.jacorb.orb.ORB.destroy(ORB.java:1870)
[junit] at com.sun.jndi.cosnaming.OrbReuseTracker.decRefCount(OrbReuseTracker.java:49)
[junit] at com.sun.jndi.cosnaming.CNCtx.close(CNCtx.java:1133)
[junit] at com.sun.jndi.cosnaming.CNCtx.finalize(CNCtx.java:1138)
[junit] at java.lang.ref.Finalizer.invokeFinalizeMethod(Native Method)
[junit] at java.lang.ref.Finalizer.runFinalizer(Finalizer.java:83)
[junit] at java.lang.ref.Finalizer.access$100(Finalizer.java:14)
[junit] at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:160)

There is an OrbReuseTracker to decrease the reference count from JVM Finalizer.
In JDK5, there isn't OrbReuseTracker class in JVM rt.jar.

[shelly.mcgowan]

This was interesting -
http://bugs.sun.com/bugdatabase/view_bug.do;jsessionid=fd40a0e2c4c9b79adab12ca088bd?bug_id=6520484