QA test suite failure: CrashRecovery05_1_Test01 ----------------------------------------------- Key: JBTM-1978 URL: https://issues.jboss.org/browse/JBTM-1978 Project: JBoss Transaction Manager Issue Type: Bug Security Level: Public(Everyone can see) Components: Testing Reporter: Gytis Trikleris Assignee: Tom Jenkinson Priority: Minor Fix For: 5.0.0.Final http://172.17.131.2/view/Narayana+BlackTie/job/narayana/303/TESTS=QA_JTS_... client0_output.txt: {code} starting command: /usr/local/jdk1.7.0_17/bin/java -classpath dist/narayana-full-5.0.0.Final-SNAPSHOT/etc/:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/ext/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/etc/:ext/fscontext.jar:ext/providerutil.jar:ext/jboss-profiler-jvmti.jar:ext/jboss-logging-spi.jar:tests/build/classes/:dbdrivers/selected_dbdriver/*:dbdrivers/DB2_v9.7/db2jcc.jar:dbdrivers/jConnect-6_0/classes/jconn3.jar:dbdrivers/mssql2005_sqljdbc_2.0/enu/sqljdbc4.jar:dbdrivers/mysql-connector-java-5.1.8-bin.jar:dbdrivers/oracle_10_2_0_4/ojdbc14.jar:dbdrivers/postgresql-8.3-605.jdbc4.jar:ext/netty.jar -Dqa.debug=true -Djava.naming.provider.url=file:///tmp -Djava.naming.factory.initial=com.sun.jndi.fscontext.RefFSContextFactory -Dperformanceprofilestore.dir=config/perf_profiles/ -Djdbcprofilestore.dir=config/jdbc_profiles -Dmemorytestprofilestore.dir=config/memory_profiles/ -Dots.server.bindname=value_1 -DCoordinatorEnvironmentBean.maintainHeuristics=NO -DRecoveryEnvironmentBean.recoveryBackoffPeriod=5 -DCoreEnvironmentBean.timeoutFactor=2 -DCoordinatorEnvironmentBean.defaultTimeout=240 -DCoordinatorEnvironmentBean.dynamic1PC=false -Demma.coverage.out.file=./testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/client0-coverage.ec -DportOffsetId=3 -DObjectStoreBaseDir=/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/client -DRecoveryEnvironmentBean.recoveryListener=true org.jboss.jbossts.qa.CrashRecovery05Clients1.Client01b value_1 2013-10-11 20:34:34,355 err: log4j:WARN No appenders could be found for logger (org.jboss.logging). 2013-10-11 20:34:34,355 err: log4j:WARN Please initialize the log4j system properly. 2013-10-11 20:34:34,421 err: SLF4J: Class path contains multiple SLF4J bindings. 2013-10-11 20:34:34,421 err: SLF4J: Found binding in [jar:file:/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/ext/slf4j-simple.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2013-10-11 20:34:34,421 err: SLF4J: Found binding in [jar:file:/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/lib/slf4j-jdk14-1.5.6.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2013-10-11 20:34:34,426 err: SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2013-10-11 20:34:34,439 err: 10 [main] INFO jacorb.config - base configuration loaded from classpath orb.properties 2013-10-11 20:34:34,440 err: 11 [main] WARN jacorb.config - File e:/JacORB_CONFIG_FEATURE/etc/jacorb.properties for configuration jacorb not found 2013-10-11 20:34:34,449 err: 20 [main] INFO jacorb.config - configuration jacorb loaded from classpath 2013-10-11 20:34:34,466 err: 37 [main] INFO jacorb.orb.print_version - 2013-10-11 20:34:34,466 err: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2013-10-11 20:34:34,466 err: JacORB V 2.3.1 (JBoss patch01), www.jacorb.org 2013-10-11 20:34:34,466 err: (C) The JacORB project 29-Jul-2009 2013-10-11 20:34:34,466 err: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2013-10-11 20:34:34,538 err: 109 [main] INFO jacorb.orb - Property "jacorb.hashtable_class" is set to: java.util.Hashtable 2013-10-11 20:34:34,585 err: 156 [main] INFO jacorb.orb.interceptors - InterceptorManager started with 1 Server Interceptors, 1 Client Interceptors and 1 IOR Interceptors 2013-10-11 20:34:34,784 err: 355 [main] INFO jacorb.config - base configuration loaded from classpath orb.properties 2013-10-11 20:34:34,784 err: 355 [main] WARN jacorb.config - File e:/JacORB_CONFIG_FEATURE/etc/jacorb.properties for configuration jacorb not found 2013-10-11 20:34:34,786 err: 357 [main] INFO jacorb.config - configuration jacorb loaded from classpath 2013-10-11 20:34:34,786 err: 357 [main] INFO jacorb.orb.singleton - created ORBSingleton 2013-10-11 20:34:34,877 err: 448 [main] INFO jacorb.poa - oid: 2013-10-11 20:34:34,878 err: 00 18 06 33 00 42 25 11 01 0F 11 ...3.B%.... 2013-10-11 20:34:34,878 err: object is activated 2013-10-11 20:34:34,880 err: 451 [main] INFO jacorb.poa - Using server ID (3870081024) for transient POA 2013-10-11 20:34:34,989 err: 560 [main] INFO jacorb.orb.giop - ClientConnectionManager: created new ClientGIOPConnection to 172.17.131.34:54307 (b8872d0) 2013-10-11 20:34:35,111 err: 682 [main] INFO jacorb.poa - oid: 2013-10-11 20:34:35,111 err: 01 18 06 33 00 42 25 11 01 0F 11 ...3.B%.... 2013-10-11 20:34:35,111 err: object is activated 2013-10-11 20:34:35,114 err: 685 [main] INFO jacorb.orb.giop - ClientConnectionManager: created new ClientGIOPConnection to 172.17.131.34:42337 (e33ad7) 2013-10-11 20:34:35,153 err: 724 [main] INFO jacorb.orb.iiop - Connected to 172.17.131.34:42337 from local port 52671 2013-10-11 20:34:35,298 err: 869 [ServerSocketListener] INFO jacorb.orb.iiop - Opened new server-side TCP/IP transport to 172.17.131.34:54297 2013-10-11 20:34:35,326 err: 896 [RequestProcessor-4] INFO jacorb.poa - oid: 2013-10-11 20:34:35,326 err: 02 18 06 33 00 42 25 11 01 0F 11 ...3.B%.... 2013-10-11 20:34:35,326 err: object is activated 2013-10-11 20:34:35,374 err: 945 [RequestProcessor-4] INFO jacorb.orb.giop - ClientConnectionManager: found ClientGIOPConnection to 172.17.131.34:42337 (e33ad7) 2013-10-11 20:34:35,754 err: 1325 [ClientMessageReceptor1] INFO jacorb.orb.iiop - Client-side TCP transport to 172.17.131.34:42337 closed. 2013-10-11 20:34:35,754 err: 1325 [ClientMessageReceptor1] WARN jacorb.giop.conn - Abnormal connection termination. Lost 1 outstanding replie(s)! 2013-10-11 20:34:35,757 out: 2013-10-11 20:34:35,757 [main] WARN com.arjuna.ats.arjuna - ARJUNA012084: One-phase commit of action 0:ffffac118322:9684:525852ca:3 received heuristic decision: TwoPhaseOutcome.HEURISTIC_HAZARD 2013-10-11 20:34:35,768 err: 1339 [ServerMessageReceptor0] INFO jacorb.orb.iiop - Closed server-side transport to 172.17.131.34:54297 2013-10-11 20:34:35,810 err: 1381 [main] INFO jacorb.orb.iiop - Retrying to connect to 172.17.131.34:42337 2013-10-11 20:34:36,311 err: 1882 [main] INFO jacorb.orb.iiop - Retrying to connect to 172.17.131.34:42337 2013-10-11 20:34:36,812 err: 2383 [main] INFO jacorb.orb.iiop - Retrying to connect to 172.17.131.34:42337 2013-10-11 20:34:37,313 err: 2883 [main] INFO jacorb.orb.iiop - Retrying to connect to 172.17.131.34:42337 2013-10-11 20:34:37,813 err: 3384 [main] INFO jacorb.orb.iiop - Retrying to connect to 172.17.131.34:42337 2013-10-11 20:34:38,328 out: 2013-10-11 20:34:38,316 [main] WARN com.arjuna.ats.jts - ARJUNA022230: ResourceRecord.forgetHeuristic caught exception 2013-10-11 20:34:38,328 out: org.omg.CORBA.TRANSIENT: Retries exceeded, couldn't reconnect to 172.17.131.34:42337 vmcid: 0x0 minor code: 0 completed: No 2013-10-11 20:34:38,328 out: at org.jacorb.orb.iiop.ClientIIOPConnection.connect(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.giop.GIOPConnection.sendMessage(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.giop.GIOPConnection.sendRequest(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.giop.ClientConnection.sendRequest(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.giop.ClientConnection.sendRequest(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.Delegate.invoke_internal(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.Delegate.invoke(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.Delegate.is_a(Unknown Source) 2013-10-11 20:34:38,328 out: at org.omg.CORBA.portable.ObjectImpl._is_a(ObjectImpl.java:130) 2013-10-11 20:34:38,328 out: at org.omg.CosTransactions.TransactionalObjectHelper.narrow(TransactionalObjectHelper.java:57) 2013-10-11 20:34:38,328 out: at com.arjuna.ats.jts.orbspecific.jacorb.interceptors.interposition.InterpositionClientRequestInterceptorImpl.send_request(InterpositionClientRequestInterceptorImpl.java:141) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.portableInterceptor.ClientInterceptorIterator.invoke(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.portableInterceptor.AbstractInterceptorIterator.iterate(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.portableInterceptor.ClientInterceptorIterator.iterate(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.ClientInterceptorHandler.invokeInterceptors(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.ClientInterceptorHandler.handle_send_request(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.Delegate.invoke_internal(Unknown Source) 2013-10-11 20:34:38,328 out: at org.jacorb.orb.Delegate.invoke(Unknown Source) 2013-10-11 20:34:38,328 out: at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:475) 2013-10-11 20:34:38,328 out: at org.omg.CosTransactions._ResourceStub.forget(_ResourceStub.java:205) 2013-10-11 20:34:38,329 out: at com.arjuna.ats.internal.jts.resources.ResourceRecord.forgetHeuristic(ResourceRecord.java:569) 2013-10-11 20:34:38,329 out: at com.arjuna.ats.arjuna.coordinator.BasicAction.doForget(BasicAction.java:3510) 2013-10-11 20:34:38,329 out: at com.arjuna.ats.arjuna.coordinator.BasicAction.forgetHeuristics(BasicAction.java:1329) 2013-10-11 20:34:38,329 out: at com.arjuna.ats.internal.jts.orbspecific.coordinator.ArjunaTransactionImple.forgetHeuristics(ArjunaTransactionImple.java:1365) 2013-10-11 20:34:38,329 out: at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2429) 2013-10-11 20:34:38,329 out: at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1475) 2013-10-11 20:34:38,329 out: at com.arjuna.ats.internal.jts.orbspecific.coordinator.ArjunaTransactionImple.commit(ArjunaTransactionImple.java:375) 2013-10-11 20:34:38,329 out: at com.arjuna.ats.internal.jts.ControlWrapper.commit(ControlWrapper.java:243) 2013-10-11 20:34:38,329 out: at com.arjuna.ats.internal.jts.orbspecific.CurrentImple.commit(CurrentImple.java:247) 2013-10-11 20:34:38,329 out: at org.jboss.jbossts.qa.CrashRecovery05Clients1.Client01b.main(Client01b.java:93) 2013-10-11 20:34:38,371 err: 3941 [main] INFO jacorb.orb.giop - ClientConnectionManager: found ClientGIOPConnection to 172.17.131.34:54307 (b8872d0) 2013-10-11 20:34:38,371 err: 3942 [ServerSocketListener] INFO jacorb.orb.iiop - Opened new server-side TCP/IP transport to 172.17.131.34:54304 2013-10-11 20:34:38,372 err: 3943 [main] INFO jacorb.orb.iiop - Connected to 172.17.131.34:54307 from local port 54304 2013-10-11 20:34:38,374 err: 3945 [AOM_RemovalThread] INFO jacorb.poa - oid: 2013-10-11 20:34:38,374 err: 01 18 06 33 00 42 25 11 01 0F 11 ...3.B%.... 2013-10-11 20:34:38,374 err: object is deactivated 2013-10-11 20:34:38,375 out: Passed 2013-10-11 20:34:38,375 err: 3946 [AOM_RemovalThread] INFO jacorb.poa - oid: 2013-10-11 20:34:38,375 err: 02 18 06 33 00 42 25 11 01 0F 11 ...3.B%.... 2013-10-11 20:34:38,375 err: object is deactivated 2013-10-11 20:34:38,378 err: 3949 [POADestructor] INFO jacorb.poa - POA RootPOA destroyed 2013-10-11 20:34:38,378 err: 3949 [main] INFO jacorb.orb - prepare ORB for shutdown... 2013-10-11 20:34:38,378 err: 3949 [main] INFO jacorb.orb - ORB going down... 2013-10-11 20:34:38,379 err: 3950 [ServerSocketListener] INFO jacorb.orb.iiop - Listener exited 2013-10-11 20:34:38,382 err: 3952 [main] INFO jacorb.orb.iiop - Closed server-side transport to 172.17.131.34:54304 2013-10-11 20:34:38,382 err: 3952 [main] INFO jacorb.orb.iiop - Client-side TCP transport to 172.17.131.34:54307 closed. 2013-10-11 20:34:38,382 err: 3952 [main] INFO jacorb.orb - ORB shutdown complete 2013-10-11 20:34:38,382 err: 3952 [ClientMessageReceptor0] INFO jacorb.giop.conn - Received CloseConnection on ClientGIOPConnection to 172.17.131.34:54307 (b8872d0) 2013-10-11 20:34:38,382 err: 3952 [ClientMessageReceptor0] INFO jacorb.util.tpool - ConsumerTie exited 2013-10-11 20:34:38,382 err: 3953 [ServerMessageReceptor0] INFO jacorb.orb.iiop - Closed server-side transport to 172.17.131.34:54304 2013-10-11 20:34:38,382 err: 3953 [ServerMessageReceptor0] INFO jacorb.util.tpool - ConsumerTie exited 2013-10-11 20:34:38,382 err: 3953 [ClientMessageReceptor1] INFO jacorb.util.tpool - ConsumerTie exited {code} client1_output.txt {code} starting command: /usr/local/jdk1.7.0_17/bin/java -classpath dist/narayana-full-5.0.0.Final-SNAPSHOT/etc/:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/ext/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/etc/:ext/fscontext.jar:ext/providerutil.jar:ext/jboss-profiler-jvmti.jar:ext/jboss-logging-spi.jar:tests/build/classes/:dbdrivers/selected_dbdriver/*:dbdrivers/DB2_v9.7/db2jcc.jar:dbdrivers/jConnect-6_0/classes/jconn3.jar:dbdrivers/mssql2005_sqljdbc_2.0/enu/sqljdbc4.jar:dbdrivers/mysql-connector-java-5.1.8-bin.jar:dbdrivers/oracle_10_2_0_4/ojdbc14.jar:dbdrivers/postgresql-8.3-605.jdbc4.jar:ext/netty.jar -Dqa.debug=true -Djava.naming.provider.url=file:///tmp -Djava.naming.factory.initial=com.sun.jndi.fscontext.RefFSContextFactory -Dperformanceprofilestore.dir=config/perf_profiles/ -Djdbcprofilestore.dir=config/jdbc_profiles -Dmemorytestprofilestore.dir=config/memory_profiles/ -Dots.server.bindname=value_1 -DCoordinatorEnvironmentBean.maintainHeuristics=NO -DRecoveryEnvironmentBean.recoveryBackoffPeriod=5 -DCoreEnvironmentBean.timeoutFactor=2 -DCoordinatorEnvironmentBean.defaultTimeout=240 -DCoordinatorEnvironmentBean.dynamic1PC=false -Demma.coverage.out.file=./testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/client1-coverage.ec -DportOffsetId=3 -DObjectStoreBaseDir=/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/client -DRecoveryEnvironmentBean.recoveryListener=true org.jboss.jbossts.qa.CrashRecovery05Clients1.Client01a value_2 2013-10-11 20:34:39,769 err: log4j:WARN No appenders could be found for logger (org.jboss.logging). 2013-10-11 20:34:39,769 err: log4j:WARN Please initialize the log4j system properly. 2013-10-11 20:34:39,834 err: SLF4J: Class path contains multiple SLF4J bindings. 2013-10-11 20:34:39,835 err: SLF4J: Found binding in [jar:file:/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/ext/slf4j-simple.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2013-10-11 20:34:39,835 err: SLF4J: Found binding in [jar:file:/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/lib/slf4j-jdk14-1.5.6.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2013-10-11 20:34:39,835 err: SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2013-10-11 20:34:39,848 err: 10 [main] INFO jacorb.config - base configuration loaded from classpath orb.properties 2013-10-11 20:34:39,851 err: 13 [main] WARN jacorb.config - File e:/JacORB_CONFIG_FEATURE/etc/jacorb.properties for configuration jacorb not found 2013-10-11 20:34:39,859 err: 21 [main] INFO jacorb.config - configuration jacorb loaded from classpath 2013-10-11 20:34:39,874 err: 36 [main] INFO jacorb.orb.print_version - 2013-10-11 20:34:39,874 err: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2013-10-11 20:34:39,874 err: JacORB V 2.3.1 (JBoss patch01), www.jacorb.org 2013-10-11 20:34:39,875 err: (C) The JacORB project 29-Jul-2009 2013-10-11 20:34:39,875 err: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2013-10-11 20:34:39,947 err: 108 [main] INFO jacorb.orb - Property "jacorb.hashtable_class" is set to: java.util.Hashtable 2013-10-11 20:34:39,993 err: 155 [main] INFO jacorb.orb.interceptors - InterceptorManager started with 1 Server Interceptors, 1 Client Interceptors and 1 IOR Interceptors 2013-10-11 20:34:40,192 err: 354 [main] INFO jacorb.config - base configuration loaded from classpath orb.properties 2013-10-11 20:34:40,192 err: 354 [main] WARN jacorb.config - File e:/JacORB_CONFIG_FEATURE/etc/jacorb.properties for configuration jacorb not found 2013-10-11 20:34:40,194 err: 356 [main] INFO jacorb.config - configuration jacorb loaded from classpath 2013-10-11 20:34:40,197 err: 359 [main] INFO jacorb.orb.singleton - created ORBSingleton 2013-10-11 20:34:40,283 err: 445 [main] INFO jacorb.orb.giop - ClientConnectionManager: created new ClientGIOPConnection to 172.17.131.34:44860 (512e3872) 2013-10-11 20:34:40,307 err: 469 [main] INFO jacorb.orb.iiop - Connected to 172.17.131.34:44860 from local port 55790 2013-10-11 20:34:40,629 out: Using timeout delay factor of 2 2013-10-11 20:35:00,641 out: Failed 2013-10-11 20:35:00,642 err: 20804 [POADestructor] INFO jacorb.poa - POA RootPOA destroyed 2013-10-11 20:35:00,642 err: 20804 [main] INFO jacorb.orb - prepare ORB for shutdown... 2013-10-11 20:35:00,642 err: 20804 [main] INFO jacorb.orb - ORB going down... 2013-10-11 20:35:00,645 err: 20805 [main] INFO jacorb.orb.iiop - Client-side TCP transport to 172.17.131.34:44860 closed. 2013-10-11 20:35:00,645 err: 20805 [main] INFO jacorb.orb - ORB shutdown complete 2013-10-11 20:35:00,645 err: 20806 [ServerSocketListener] INFO jacorb.orb.iiop - Listener exited 2013-10-11 20:35:00,647 err: 20809 [ClientMessageReceptor0] INFO jacorb.util.tpool - ConsumerTie exited {code} server0_output.txt {code} starting command: /usr/local/jdk1.7.0_17/bin/java -classpath dist/narayana-full-5.0.0.Final-SNAPSHOT/etc/:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/ext/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/etc/:ext/fscontext.jar:ext/providerutil.jar:ext/jboss-profiler-jvmti.jar:ext/jboss-logging-spi.jar:tests/build/classes/:dbdrivers/selected_dbdriver/*:dbdrivers/DB2_v9.7/db2jcc.jar:dbdrivers/jConnect-6_0/classes/jconn3.jar:dbdrivers/mssql2005_sqljdbc_2.0/enu/sqljdbc4.jar:dbdrivers/mysql-connector-java-5.1.8-bin.jar:dbdrivers/oracle_10_2_0_4/ojdbc14.jar:dbdrivers/postgresql-8.3-605.jdbc4.jar:ext/netty.jar -Dqa.debug=true -Djava.naming.provider.url=file:///tmp -Djava.naming.factory.initial=com.sun.jndi.fscontext.RefFSContextFactory -Dperformanceprofilestore.dir=config/perf_profiles/ -Djdbcprofilestore.dir=config/jdbc_profiles -Dmemorytestprofilestore.dir=config/memory_profiles/ -Dots.server.bindname=value_1 -DCoordinatorEnvironmentBean.maintainHeuristics=NO -DRecoveryEnvironmentBean.recoveryBackoffPeriod=5 -DCoreEnvironmentBean.timeoutFactor=2 -DCoordinatorEnvironmentBean.defaultTimeout=240 -DCoordinatorEnvironmentBean.dynamic1PC=false -Demma.coverage.out.file=./testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/server0-coverage.ec -DportOffsetId=1 -DObjectStoreBaseDir=/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/server0 -DRecoveryEnvironmentBean.recoveryListener=true com.arjuna.ats.arjuna.recovery.RecoveryManager -test 2013-10-11 20:34:32,252 err: log4j:WARN No appenders could be found for logger (org.jboss.logging). 2013-10-11 20:34:32,252 err: log4j:WARN Please initialize the log4j system properly. 2013-10-11 20:34:32,355 err: SLF4J: Class path contains multiple SLF4J bindings. 2013-10-11 20:34:32,355 err: SLF4J: Found binding in [jar:file:/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/ext/slf4j-simple.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2013-10-11 20:34:32,355 err: SLF4J: Found binding in [jar:file:/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/lib/slf4j-jdk14-1.5.6.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2013-10-11 20:34:32,356 err: SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2013-10-11 20:34:32,361 err: 3 [main] INFO jacorb.config - base configuration loaded from classpath orb.properties 2013-10-11 20:34:32,361 err: 3 [main] WARN jacorb.config - File e:/JacORB_CONFIG_FEATURE/etc/jacorb.properties for configuration jacorb not found 2013-10-11 20:34:32,363 err: 5 [main] INFO jacorb.config - configuration jacorb loaded from classpath 2013-10-11 20:34:32,378 err: 20 [main] INFO jacorb.orb.print_version - 2013-10-11 20:34:32,378 err: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2013-10-11 20:34:32,378 err: JacORB V 2.3.1 (JBoss patch01), www.jacorb.org 2013-10-11 20:34:32,378 err: (C) The JacORB project 29-Jul-2009 2013-10-11 20:34:32,378 err: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2013-10-11 20:34:32,449 err: 91 [main] INFO jacorb.orb - Property "jacorb.hashtable_class" is set to: java.util.Hashtable 2013-10-11 20:34:32,495 err: 137 [main] INFO jacorb.orb.interceptors - InterceptorManager started with 1 Server Interceptors, 1 Client Interceptors and 1 IOR Interceptors 2013-10-11 20:34:32,722 err: 364 [main] INFO jacorb.config - base configuration loaded from classpath orb.properties 2013-10-11 20:34:32,722 err: 364 [main] WARN jacorb.config - File e:/JacORB_CONFIG_FEATURE/etc/jacorb.properties for configuration jacorb not found 2013-10-11 20:34:32,724 err: 366 [main] INFO jacorb.config - configuration jacorb loaded from classpath 2013-10-11 20:34:32,727 err: 369 [main] INFO jacorb.orb.singleton - created ORBSingleton 2013-10-11 20:34:32,866 err: 508 [Thread-3] INFO jacorb.orb - ORB run 2013-10-11 20:34:32,962 out: Ready 2013-10-11 20:34:40,464 err: 8104 [ServerSocketListener] INFO jacorb.orb.iiop - Opened new server-side TCP/IP transport to 172.17.131.34:54289 2013-10-11 20:34:40,575 err: 8217 [RequestProcessor-4] INFO jacorb.orb.giop - ClientConnectionManager: created new ClientGIOPConnection to 172.17.131.34:54307 (2451c70d) 2013-10-11 20:34:40,587 err: 8229 [RequestProcessor-4] INFO jacorb.orb.iiop - Connected to 172.17.131.34:54307 from local port 54307 2013-10-11 20:34:40,589 err: 8230 [ClientMessageReceptor0] WARN jacorb.orb.giop - Received a request on a non-bidir connection 2013-10-11 20:34:40,605 out: 2013-10-11 20:34:40,595 [RequestProcessor-4] WARN com.arjuna.ats.jts - ARJUNA022139: CORBA exception on trying to contact original process 2013-10-11 20:34:40,606 out: org.omg.CORBA.INV_POLICY: Server-side Exception: null vmcid: 0x0 minor code: 0 completed: No 2013-10-11 20:34:40,606 out: at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) 2013-10-11 20:34:40,606 out: at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) 2013-10-11 20:34:40,606 out: at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) 2013-10-11 20:34:40,606 out: at java.lang.reflect.Constructor.newInstance(Constructor.java:525) 2013-10-11 20:34:40,606 out: at org.jacorb.orb.SystemExceptionHelper.read(Unknown Source) 2013-10-11 20:34:40,606 out: at org.jacorb.orb.ReplyReceiver.getReply(Unknown Source) 2013-10-11 20:34:40,606 out: at org.jacorb.orb.Delegate.invoke_internal(Unknown Source) 2013-10-11 20:34:40,606 out: at org.jacorb.orb.Delegate.invoke(Unknown Source) 2013-10-11 20:34:40,606 out: at org.jacorb.orb.Delegate.is_a(Unknown Source) 2013-10-11 20:34:40,606 out: at org.omg.CORBA.portable.ObjectImpl._is_a(ObjectImpl.java:130) 2013-10-11 20:34:40,606 out: at org.omg.CosTransactions.TransactionalObjectHelper.narrow(TransactionalObjectHelper.java:57) 2013-10-11 20:34:40,606 out: at com.arjuna.ats.jts.orbspecific.jacorb.interceptors.interposition.InterpositionClientRequestInterceptorImpl.send_request(InterpositionClientRequestInterceptorImpl.java:141) 2013-10-11 20:34:40,606 out: at org.jacorb.orb.portableInterceptor.ClientInterceptorIterator.invoke(Unknown Source) 2013-10-11 20:34:40,606 out: at org.jacorb.orb.portableInterceptor.AbstractInterceptorIterator.iterate(Unknown Source) 2013-10-11 20:34:40,607 out: at org.jacorb.orb.portableInterceptor.ClientInterceptorIterator.iterate(Unknown Source) 2013-10-11 20:34:40,607 out: at org.jacorb.orb.ClientInterceptorHandler.invokeInterceptors(Unknown Source) 2013-10-11 20:34:40,607 out: at org.jacorb.orb.ClientInterceptorHandler.handle_send_request(Unknown Source) 2013-10-11 20:34:40,607 out: at org.jacorb.orb.Delegate.invoke_internal(Unknown Source) 2013-10-11 20:34:40,607 out: at org.jacorb.orb.Delegate.invoke(Unknown Source) 2013-10-11 20:34:40,607 out: at org.omg.CORBA.portable.ObjectImpl._invoke(ObjectImpl.java:475) 2013-10-11 20:34:40,607 out: at com.arjuna.ArjunaOTS._ArjunaFactoryStub.getCurrentStatus(_ArjunaFactoryStub.java:31) 2013-10-11 20:34:40,607 out: at com.arjuna.ats.internal.jts.recovery.contact.StatusChecker.getStatus(StatusChecker.java:176) 2013-10-11 20:34:40,607 out: at com.arjuna.ats.internal.jts.recovery.contact.StatusChecker.checkOriginalStatus(StatusChecker.java:144) 2013-10-11 20:34:40,607 out: at com.arjuna.ats.internal.jts.recovery.contact.StatusChecker.get_current_status(StatusChecker.java:110) 2013-10-11 20:34:40,607 out: at com.arjuna.ats.internal.jts.orbspecific.recovery.recoverycoordinators.GenericRecoveryCoordinator.get_status(GenericRecoveryCoordinator.java:328) 2013-10-11 20:34:40,607 out: at com.arjuna.ats.internal.jts.orbspecific.recovery.recoverycoordinators.GenericRecoveryCoordinator.replay_completion(GenericRecoveryCoordinator.java:145) 2013-10-11 20:34:40,607 out: at com.arjuna.ats.internal.jts.orbspecific.jacorb.recoverycoordinators.JacOrbRCDefaultServant.replay_completion(JacOrbRCDefaultServant.java:90) 2013-10-11 20:34:40,607 out: at org.omg.CosTransactions.RecoveryCoordinatorPOA._invoke(RecoveryCoordinatorPOA.java:44) 2013-10-11 20:34:40,607 out: at org.jacorb.poa.RequestProcessor.invokeOperation(Unknown Source) 2013-10-11 20:34:40,607 out: at org.jacorb.poa.RequestProcessor.process(Unknown Source) 2013-10-11 20:34:40,607 out: at org.jacorb.poa.RequestProcessor.run(Unknown Source) {code} server1_output.txt {code} starting command: /usr/local/jdk1.7.0_17/bin/java -classpath dist/narayana-full-5.0.0.Final-SNAPSHOT/etc/:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/ext/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/etc/:ext/fscontext.jar:ext/providerutil.jar:ext/jboss-profiler-jvmti.jar:ext/jboss-logging-spi.jar:tests/build/classes/:dbdrivers/selected_dbdriver/*:dbdrivers/DB2_v9.7/db2jcc.jar:dbdrivers/jConnect-6_0/classes/jconn3.jar:dbdrivers/mssql2005_sqljdbc_2.0/enu/sqljdbc4.jar:dbdrivers/mysql-connector-java-5.1.8-bin.jar:dbdrivers/oracle_10_2_0_4/ojdbc14.jar:dbdrivers/postgresql-8.3-605.jdbc4.jar:ext/netty.jar -Dqa.debug=true -Djava.naming.provider.url=file:///tmp -Djava.naming.factory.initial=com.sun.jndi.fscontext.RefFSContextFactory -Dperformanceprofilestore.dir=config/perf_profiles/ -Djdbcprofilestore.dir=config/jdbc_profiles -Dmemorytestprofilestore.dir=config/memory_profiles/ -Dots.server.bindname=value_1 -DCoordinatorEnvironmentBean.maintainHeuristics=NO -DRecoveryEnvironmentBean.recoveryBackoffPeriod=5 -DCoreEnvironmentBean.timeoutFactor=2 -DCoordinatorEnvironmentBean.defaultTimeout=240 -DCoordinatorEnvironmentBean.dynamic1PC=false -Demma.coverage.out.file=./testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/server1-coverage.ec -DportOffsetId=2 -DObjectStoreBaseDir=/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/server -DRecoveryEnvironmentBean.recoveryListener=true org.jboss.jbossts.qa.CrashRecovery05Servers.Server01 value_3 value_1 2013-10-11 20:34:33,392 err: log4j:WARN No appenders could be found for logger (org.jboss.logging). 2013-10-11 20:34:33,392 err: log4j:WARN Please initialize the log4j system properly. 2013-10-11 20:34:33,458 err: SLF4J: Class path contains multiple SLF4J bindings. 2013-10-11 20:34:33,458 err: SLF4J: Found binding in [jar:file:/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/ext/slf4j-simple.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2013-10-11 20:34:33,458 err: SLF4J: Found binding in [jar:file:/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/lib/slf4j-jdk14-1.5.6.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2013-10-11 20:34:33,458 err: SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2013-10-11 20:34:33,470 err: 9 [main] INFO jacorb.config - base configuration loaded from classpath orb.properties 2013-10-11 20:34:33,473 err: 12 [main] WARN jacorb.config - File e:/JacORB_CONFIG_FEATURE/etc/jacorb.properties for configuration jacorb not found 2013-10-11 20:34:33,482 err: 21 [main] INFO jacorb.config - configuration jacorb loaded from classpath 2013-10-11 20:34:33,498 err: 37 [main] INFO jacorb.orb.print_version - 2013-10-11 20:34:33,498 err: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2013-10-11 20:34:33,498 err: JacORB V 2.3.1 (JBoss patch01), www.jacorb.org 2013-10-11 20:34:33,498 err: (C) The JacORB project 29-Jul-2009 2013-10-11 20:34:33,498 err: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2013-10-11 20:34:33,575 err: 114 [main] INFO jacorb.orb - Property "jacorb.hashtable_class" is set to: java.util.Hashtable 2013-10-11 20:34:33,622 err: 161 [main] INFO jacorb.orb.interceptors - InterceptorManager started with 1 Server Interceptors, 1 Client Interceptors and 1 IOR Interceptors 2013-10-11 20:34:33,803 out: BeforeCrashServiceImpl01(231605477, 0) 2013-10-11 20:34:33,804 err: 343 [main] INFO jacorb.poa - oid: 2013-10-11 20:34:33,804 err: 00 18 06 33 00 42 14 0E 17 4D ...3.B...M 2013-10-11 20:34:33,804 err: object is activated 2013-10-11 20:34:33,810 err: 348 [main] INFO jacorb.poa - Using server ID (3589635481) for transient POA 2013-10-11 20:34:33,850 err: 389 [main] INFO jacorb.config - base configuration loaded from classpath orb.properties 2013-10-11 20:34:33,850 err: 389 [main] WARN jacorb.config - File e:/JacORB_CONFIG_FEATURE/etc/jacorb.properties for configuration jacorb not found 2013-10-11 20:34:33,852 err: 391 [main] INFO jacorb.config - configuration jacorb loaded from classpath 2013-10-11 20:34:33,852 err: 391 [main] INFO jacorb.orb.singleton - created ORBSingleton 2013-10-11 20:34:33,914 err: 453 [main] INFO jacorb.orb.giop - ClientConnectionManager: created new ClientGIOPConnection to 172.17.131.34:42337 (59966240) 2013-10-11 20:34:33,925 out: Ready 2013-10-11 20:34:33,926 err: 465 [main] INFO jacorb.orb - ORB run 2013-10-11 20:34:35,151 err: 1690 [ServerSocketListener] INFO jacorb.orb.iiop - Opened new server-side TCP/IP transport to 172.17.131.34:52671 2013-10-11 20:34:35,234 err: 1773 [RequestProcessor-5] INFO jacorb.orb.giop - ClientConnectionManager: created new ClientGIOPConnection to 172.17.131.34:54307 (d13e8c7) 2013-10-11 20:34:35,271 err: 1810 [RequestProcessor-5] INFO jacorb.poa - oid: 2013-10-11 20:34:35,271 err: 01 18 06 33 00 42 14 0E 17 4D ...3.B...M 2013-10-11 20:34:35,271 err: object is activated 2013-10-11 20:34:35,273 err: 1811 [RequestProcessor-5] INFO jacorb.orb.giop - ClientConnectionManager: found ClientGIOPConnection to 172.17.131.34:42337 (59966240) 2013-10-11 20:34:35,301 err: 1840 [RequestProcessor-5] INFO jacorb.orb.iiop - Connected to 172.17.131.34:54307 from local port 54297 2013-10-11 20:34:35,333 err: 1870 [RequestProcessor-5] INFO jacorb.orb.giop - ClientConnectionManager: found ClientGIOPConnection to 172.17.131.34:54307 (d13e8c7) 2013-10-11 20:34:35,389 out: BeforeCrashServiceImpl01: storing IOR "RecoveryCoordinator_231605477_0_0" 2013-10-11 20:34:35,428 err: BeforeCrashServiceImpl01.is_correct: true 2013-10-11 20:34:35,434 err: ResourceImpl01.commit_one_phase [O0.R0]: Crash {code} server2_output.txt {code} starting command: /usr/local/jdk1.7.0_17/bin/java -classpath dist/narayana-full-5.0.0.Final-SNAPSHOT/etc/:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/ext/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/etc/:ext/fscontext.jar:ext/providerutil.jar:ext/jboss-profiler-jvmti.jar:ext/jboss-logging-spi.jar:tests/build/classes/:dbdrivers/selected_dbdriver/*:dbdrivers/DB2_v9.7/db2jcc.jar:dbdrivers/jConnect-6_0/classes/jconn3.jar:dbdrivers/mssql2005_sqljdbc_2.0/enu/sqljdbc4.jar:dbdrivers/mysql-connector-java-5.1.8-bin.jar:dbdrivers/oracle_10_2_0_4/ojdbc14.jar:dbdrivers/postgresql-8.3-605.jdbc4.jar:ext/netty.jar -Dqa.debug=true -Djava.naming.provider.url=file:///tmp -Djava.naming.factory.initial=com.sun.jndi.fscontext.RefFSContextFactory -Dperformanceprofilestore.dir=config/perf_profiles/ -Djdbcprofilestore.dir=config/jdbc_profiles -Dmemorytestprofilestore.dir=config/memory_profiles/ -Dots.server.bindname=value_1 -DCoordinatorEnvironmentBean.maintainHeuristics=NO -DRecoveryEnvironmentBean.recoveryBackoffPeriod=5 -DCoreEnvironmentBean.timeoutFactor=2 -DCoordinatorEnvironmentBean.defaultTimeout=240 -DCoordinatorEnvironmentBean.dynamic1PC=false -Demma.coverage.out.file=./testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/server2-coverage.ec -DportOffsetId=2 -DObjectStoreBaseDir=/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/server -DRecoveryEnvironmentBean.recoveryListener=true org.jboss.jbossts.qa.CrashRecovery05Servers.Server02 value_3 value_2 2013-10-11 20:34:38,819 err: log4j:WARN No appenders could be found for logger (org.jboss.logging). 2013-10-11 20:34:38,820 err: log4j:WARN Please initialize the log4j system properly. 2013-10-11 20:34:38,885 err: SLF4J: Class path contains multiple SLF4J bindings. 2013-10-11 20:34:38,885 err: SLF4J: Found binding in [jar:file:/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/ext/slf4j-simple.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2013-10-11 20:34:38,885 err: SLF4J: Found binding in [jar:file:/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/lib/slf4j-jdk14-1.5.6.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2013-10-11 20:34:38,885 err: SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2013-10-11 20:34:38,898 err: 10 [main] INFO jacorb.config - base configuration loaded from classpath orb.properties 2013-10-11 20:34:38,901 err: 13 [main] WARN jacorb.config - File e:/JacORB_CONFIG_FEATURE/etc/jacorb.properties for configuration jacorb not found 2013-10-11 20:34:38,909 err: 21 [main] INFO jacorb.config - configuration jacorb loaded from classpath 2013-10-11 20:34:38,925 err: 37 [main] INFO jacorb.orb.print_version - 2013-10-11 20:34:38,926 err: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2013-10-11 20:34:38,926 err: JacORB V 2.3.1 (JBoss patch01), www.jacorb.org 2013-10-11 20:34:38,926 err: (C) The JacORB project 29-Jul-2009 2013-10-11 20:34:38,926 err: ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2013-10-11 20:34:39,001 err: 112 [main] INFO jacorb.orb - Property "jacorb.hashtable_class" is set to: java.util.Hashtable 2013-10-11 20:34:39,045 err: 157 [main] INFO jacorb.orb.interceptors - InterceptorManager started with 1 Server Interceptors, 1 Client Interceptors and 1 IOR Interceptors 2013-10-11 20:34:39,228 out: AfterCrashServiceImpl01(231605477, 0) 2013-10-11 20:34:39,232 err: 344 [main] INFO jacorb.poa - oid: 2013-10-11 20:34:39,233 err: 00 18 06 33 00 43 2C 4B 21 2D ...3.C,K!- 2013-10-11 20:34:39,233 err: object is activated 2013-10-11 20:34:39,235 err: 347 [main] INFO jacorb.poa - Using server ID (1830494895) for transient POA 2013-10-11 20:34:39,275 err: 387 [main] INFO jacorb.config - base configuration loaded from classpath orb.properties 2013-10-11 20:34:39,275 err: 387 [main] WARN jacorb.config - File e:/JacORB_CONFIG_FEATURE/etc/jacorb.properties for configuration jacorb not found 2013-10-11 20:34:39,277 err: 389 [main] INFO jacorb.config - configuration jacorb loaded from classpath 2013-10-11 20:34:39,279 err: 391 [main] INFO jacorb.orb.singleton - created ORBSingleton 2013-10-11 20:34:39,337 err: 449 [main] INFO jacorb.orb.giop - ClientConnectionManager: created new ClientGIOPConnection to 172.17.131.34:44860 (5c2f4f8b) 2013-10-11 20:34:39,356 out: Ready 2013-10-11 20:34:39,357 err: 469 [main] INFO jacorb.orb - ORB run 2013-10-11 20:34:40,306 err: 1418 [ServerSocketListener] INFO jacorb.orb.iiop - Opened new server-side TCP/IP transport to 172.17.131.34:55790 2013-10-11 20:34:40,401 err: 1513 [RequestProcessor-5] INFO jacorb.poa - oid: 2013-10-11 20:34:40,401 err: 01 18 06 33 00 43 2C 4B 21 2D ...3.C,K!- 2013-10-11 20:34:40,401 err: object is activated 2013-10-11 20:34:40,404 err: 1516 [RequestProcessor-5] INFO jacorb.orb.giop - ClientConnectionManager: found ClientGIOPConnection to 172.17.131.34:44860 (5c2f4f8b) 2013-10-11 20:34:40,409 out: AfterCrashServiceImpl01: loading IOR "RecoveryCoordinator_231605477_0_0" 2013-10-11 20:34:40,425 err: 1536 [RequestProcessor-5] INFO jacorb.orb.giop - ClientConnectionManager: created new ClientGIOPConnection to 172.17.131.34:4711 (25a226eb) 2013-10-11 20:34:40,435 err: 1547 [RequestProcessor-5] ERROR jacorb.orb - no adapter activator exists for RcvCo-RecCoService_cersei.buildnet.ncl.jboss.comrecovery_coordinator 2013-10-11 20:34:40,461 err: 1573 [RequestProcessor-5] INFO jacorb.orb.iiop - Connected to 172.17.131.34:4711 from local port 54289 2013-10-11 20:34:40,612 err: AfterCrashServiceImpl01.check_oper [O0.R0]: replay_completion returned: org.omg.CosTransactions.Status@b93c476 2013-10-11 20:35:00,640 err: AfterCrashServiceImpl01.get_resource_trace [O0.R0]: ResourceTraceNone 2013-10-11 20:35:00,646 err: 21758 [ServerMessageReceptor0] INFO jacorb.orb.iiop - Closed server-side transport to 172.17.131.34:55790 {code} task0_output.txt {code} performing command: /usr/local/jdk1.7.0_17/bin/java -classpath dist/narayana-full-5.0.0.Final-SNAPSHOT/etc/:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/lib/ext/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/lib/*:dist/narayana-full-5.0.0.Final-SNAPSHOT/jacorb/etc/:ext/fscontext.jar:ext/providerutil.jar:ext/jboss-profiler-jvmti.jar:ext/jboss-logging-spi.jar:tests/build/classes/:dbdrivers/selected_dbdriver/*:dbdrivers/DB2_v9.7/db2jcc.jar:dbdrivers/jConnect-6_0/classes/jconn3.jar:dbdrivers/mssql2005_sqljdbc_2.0/enu/sqljdbc4.jar:dbdrivers/mysql-connector-java-5.1.8-bin.jar:dbdrivers/oracle_10_2_0_4/ojdbc14.jar:dbdrivers/postgresql-8.3-605.jdbc4.jar:ext/netty.jar -Dqa.debug=true -Djava.naming.provider.url=file:///tmp -Djava.naming.factory.initial=com.sun.jndi.fscontext.RefFSContextFactory -Dperformanceprofilestore.dir=config/perf_profiles/ -Djdbcprofilestore.dir=config/jdbc_profiles -Dmemorytestprofilestore.dir=config/memory_profiles/ -Dots.server.bindname=value_1 -DCoordinatorEnvironmentBean.maintainHeuristics=NO -DRecoveryEnvironmentBean.recoveryBackoffPeriod=5 -DCoreEnvironmentBean.timeoutFactor=2 -DCoordinatorEnvironmentBean.defaultTimeout=240 -DCoordinatorEnvironmentBean.dynamic1PC=false -Demma.coverage.out.file=./testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/task0-coverage.ec -DportOffsetId=6 -DObjectStoreBaseDir=/home/hudson/workspace/narayana/TESTS/QA_JTS_JACORB/jdk/jdk7.latest/label/linux/qa/testoutput/crashrecovery05_1/CrashRecovery05_1_Test01/task0 -DRecoveryEnvironmentBean.recoveryListener=true org.jboss.jbossts.qa.Utils.RemoveServerIORStore value_1 value_2 value_3 2013-10-11 20:35:00,832 err: java.io.FileNotFoundException: ServerIORs (No such file or directory) 2013-10-11 20:35:00,832 err: at java.io.FileInputStream.open(Native Method) 2013-10-11 20:35:00,833 err: at java.io.FileInputStream.<init>(FileInputStream.java:138) 2013-10-11 20:35:00,833 err: at java.io.FileInputStream.<init>(FileInputStream.java:97) 2013-10-11 20:35:00,833 err: at org.jboss.jbossts.qa.Utils.FileServerIORStore.removeIOR(FileServerIORStore.java:69) 2013-10-11 20:35:00,833 err: at org.jboss.jbossts.qa.Utils.ServerIORStore.removeIOR(ServerIORStore.java:47) 2013-10-11 20:35:00,833 err: at org.jboss.jbossts.qa.Utils.RemoveServerIORStore.main(RemoveServerIORStore.java:42) 2013-10-11 20:35:00,834 err: java.io.FileNotFoundException: ServerIORs (No such file or directory) 2013-10-11 20:35:00,834 err: at java.io.FileInputStream.open(Native Method) 2013-10-11 20:35:00,834 err: at java.io.FileInputStream.<init>(FileInputStream.java:138) 2013-10-11 20:35:00,834 err: at java.io.FileInputStream.<init>(FileInputStream.java:97) 2013-10-11 20:35:00,834 err: at org.jboss.jbossts.qa.Utils.FileServerIORStore.removeIOR(FileServerIORStore.java:69) 2013-10-11 20:35:00,834 err: at org.jboss.jbossts.qa.Utils.ServerIORStore.removeIOR(ServerIORStore.java:47) 2013-10-11 20:35:00,835 err: at org.jboss.jbossts.qa.Utils.RemoveServerIORStore.main(RemoveServerIORStore.java:42) 2013-10-11 20:35:00,835 err: java.io.FileNotFoundException: ServerIORs (No such file or directory) 2013-10-11 20:35:00,835 err: at java.io.FileInputStream.open(Native Method) 2013-10-11 20:35:00,835 err: at java.io.FileInputStream.<init>(FileInputStream.java:138) 2013-10-11 20:35:00,835 err: at java.io.FileInputStream.<init>(FileInputStream.java:97) 2013-10-11 20:35:00,836 err: at org.jboss.jbossts.qa.Utils.FileServerIORStore.removeIOR(FileServerIORStore.java:69) 2013-10-11 20:35:00,836 err: at org.jboss.jbossts.qa.Utils.ServerIORStore.removeIOR(ServerIORStore.java:47) 2013-10-11 20:35:00,836 err: at org.jboss.jbossts.qa.Utils.RemoveServerIORStore.main(RemoveServerIORStore.java:42) 2013-10-11 20:35:00,836 out: Passed {code}