Uploaded image for project: 'ActiveMQ Artemis'
  1. ActiveMQ Artemis
  2. ARTEMIS-3435

ActiveMQTestBase.checkLibaio waits can cause hours to be added to failing test suite

    XMLWordPrintableJSON

Details

    • Test
    • Status: Resolved
    • Major
    • Resolution: Fixed
    • 2.18.0
    • 2.19.0
    • Tests
    • None

    Description

      I recently observered a 'full test' run take over an extra 3 hours, essentially doubling the time to 6hrs 40mins (repeated, it took 3hrs 30mins), with nearly 450 failures in the integration-tests module mostly all due to the same 'test did not close all its files 4096' reason.

      Investigating, I found that all the failures appeared linked and were likely caused by a single prior test having done something awry, with the effect then continuing to fail all subsequent tests classes (after they had run their tests, successfully or otherwise) using the same ActiveMQTestBase parent class for the same reason. Before invoking the fail it waits 30 seconds for the ActiveMQTestBase.checkLibaio check to assert a value hits 0after the test class, which it repeatedly didnt. This added 400+ 30sec waits to the test run, failing those 400+ test classes.

      I wasnt able to get all the classes in the output summary, the continued test output filled the buffer, but I got a couple snippets:

      [ERROR] Failures: 
      [ERROR] QuorumFailOverTest.testQuorumVotingLiveNotDead:143->ClusterTestBase.verifyReceiveRoundRobinInSomeOrder:1167->Assert.assertNotNull:713->Assert.assertTrue:42->Assert.fail:89 msg must exist
      [ERROR] PluggableQuorumReplicaTimeoutTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] PluggableQuorumReplicatedDistributionTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] PluggableQuorumReplicatedLargeMessageFailoverTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] PluggableQuorumReplicatedLargeMessageWithDelayFailoverTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] PluggableQuorumReplicatedPagingFailoverTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] FailoverWithSharedStoreTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] MultiThreadRandomReattachTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] NettyMultiThreadRandomReattachTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] OrderReattachTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] RandomReattachTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      ...lots missing...
      
      ...lots missing...
      [ERROR] FederationBrokerPluginTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] JvmMetricsTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] MetricsPluginTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] MqttPluginTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] OpenwirePluginTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ResourceBrokerPluginTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompPluginTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] XmlConfigPluginTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ActiveMQActivationTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ActiveMQClusteredTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ActiveMQMessageHandlerSecurityTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ActiveMQMessageHandlerTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ActiveMQMessageHandlerXATest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] IgnoreJTATest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] JMSContextTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] OutgoingConnectionJTATest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] OutgoingConnectionNoJTATest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] OutgoingConnectionTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ResourceAdapterTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] BatchDelayTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] DestroyConsumerTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] DirectDeliverTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] NettyNetworkAddressTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] NettySynchronousCloseTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] PingTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ReconnectTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SynchronousCloseTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] HQClientProtocolManagerTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] PluggableQuorumReplicationFlowControlTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] PluggableQuorumReplicationOrderTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] PluggableQuorumReplicationTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ReplicationOrderTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ReplicationTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SharedNothingReplicationFlowControlTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SharedNothingReplicationTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] RestDeserializationTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] DelayedMessageTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] MultipliedDelayedMessageTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ScheduledMessageTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] BasicSecurityManagerFailoverTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] BasicSecurityManagerTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] JMSXUserIDPluginTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] NettySecurityClientTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] PluggableQuorumBasicSecurityManagerFailoverTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] RejectValidatedUserTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SecurityPerAcceptorJmsTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SecurityPerAcceptorTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SecurityTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] AIOFileLockTimeoutTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ActivationCallbackTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ActivationFailureListenerTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] AddressQueryTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] AddressQueueDeleteDelayTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] AutoCreateDeadLetterResourcesTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] AutoCreateExpiryResourcesTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ConfigurationTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ConnectionLimitTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ExpiryRunnerTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] GracefulShutdownTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] LVQRecoveryTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] LVQTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] MessageExpirationTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] NIOFileLockTimeoutTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] PotentialOOMELoggingTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] PredefinedQueueTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] QueuePeristPauseTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] QueueQueryTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ResourceLimitTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] RetroactiveAddressFailoverTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] RetroactiveAddressTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] RingQueueTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ScaleDown3NodeTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ScaleDownDirectTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ScaleDownRemoveSFTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ScaleDownTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SecureConfigurationTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SimpleStartStopTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SuppliedThreadPoolTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] TempQueueNamespaceTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SpringIntegrationTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] CoreClientOverOneWaySSLTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] CoreClientOverTwoWaySSLTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] DualAuthenticationTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SSLProviderTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SSLProviderTwoWayTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] FQQNStompTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompConnectionCleanupTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompPropertiesInterceptorTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompWebSocketMaxFrameTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompWebSocketTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompWithClientIdValidationTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompWithInterceptorsTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompWithMessageIDTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompWithRejectingInterceptorTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompWithSecurityPerAcceptorTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompWithSecurityTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] ExtraStompTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompV11Test>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompV11Test.testSubscribeWithAutoAck:1946->Assert.assertNull:748->Assert.assertNull:738->Assert.failNotNull:756->Assert.fail:89 expected null, but was:<ActiveMQMessage[ID:8bff2aab-ffae-11eb-8bd9-38baf858f51b]:PERSISTENT/ClientMessageImpl[messageID=18, durable=true, address=testQueue,userID=8bff2aab-ffae-11eb-8bd9-38baf858f51b,properties=TypedProperties[__AMQ_CID=8bfe6757-ffae-11eb-8bd9-38baf858f51b,_AMQ_ROUTING_TYPE=1]]>
      [ERROR] StompV12Test>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] StompV12Test.testAckModeAuto:1235->Assert.assertNull:748->Assert.assertNull:738->Assert.failNotNull:756->Assert.fail:89 expected null, but was:<ActiveMQMessage[ID:e364ab94-ffae-11eb-8bd9-38baf858f51b]:PERSISTENT/ClientMessageImpl[messageID=83, durable=true, address=testQueue,userID=e364ab94-ffae-11eb-8bd9-38baf858f51b,properties=TypedProperties[__AMQ_CID=e3573edf-ffae-11eb-8bd9-38baf858f51b,_AMQ_ROUTING_TYPE=1]]>
      [ERROR] StompV12Test.testRedeliveryWithClientAck:1689->Assert.assertNotNull:723->Assert.assertNotNull:713->Assert.assertTrue:42->Assert.fail:87
      [ERROR] ActiveMQFrameDecoder2Test>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] NettyConnectorWithHTTPUpgradeTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] BasicXaRecoveryTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] BasicXaTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] SessionFailureXATest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [ERROR] XaTimeoutTest>ActiveMQTestBase.checkLibaio:2061->Assert.fail:89 test did not close all its files 4096
      [INFO] 
      [ERROR] Tests run: 9282, Failures: 446, Errors: 0, Skipped: 125
      [INFO] 
      [ERROR] There are test failures.
      

       

      There were also various instaces of 'AMQ229062: Acceptor with id 0 already registered' near the end that may or may not be related, e.g:

      [Thread-0 (ActiveMQ-scheduled-threads)] 00:09:34,169 WARN [org.apache.activemq.artemis.core.server] AMQ222103: transaction with xid XidImpl (644867901 bq:120.97.54 formatID:1 gtxid:50.101.49.57.101.99.101.48.45.102.102.98.48.45.49.49.101.98.45.56.98.100.57.45.51.56.98.97.102.56.53.56.102.53.49.98 base64:eGE2MmUxOWVjZTAtZmZiMC0xMWViLThiZDktMzhiYWY4NThmNTFiAQAAAA== timed out
      [main] 00:09:34,334 ERROR [org.apache.activemq.artemis.core.server] AMQ224104: Error starting the Acceptor invm \{serverId=0}
      [main] 00:09:34,334 ERROR [org.apache.activemq.artemis.core.server] AMQ224000: Failure in initialisation: java.lang.IllegalArgumentException: AMQ229062: Acceptor with id 0 already registered
       at org.apache.activemq.artemis.core.remoting.impl.invm.InVMRegistry.registerAcceptor(InVMRegistry.java:32)
       at org.apache.activemq.artemis.core.remoting.impl.invm.InVMAcceptor.start(InVMAcceptor.java:139)
       at org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl.startAcceptors(RemotingServiceImpl.java:318)
       at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.completeActivation(ActiveMQServerImpl.java:3347)
       at org.apache.activemq.artemis.core.server.impl.LiveOnlyActivation.run(LiveOnlyActivation.java:78)
       at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.internalStart(ActiveMQServerImpl.java:642)
       at org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.start(ActiveMQServerImpl.java:561)
       at org.apache.activemq.artemis.tests.integration.xa.XaTimeoutTest.setUp(XaTimeoutTest.java:111)
      ...etc...
      

      Attachments

        Issue Links

          Activity

            People

              robbie Robbie Gemmell
              robbie Robbie Gemmell
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: