TestAutomation.testFileBlobAndDocumentImport randomly failing

Run unit tests / Run mongodb unit tests / org.nuxeo.importer.stream.tests.importer.TestAutomation.testFileBlobAndDocumentImportFailing for the past 1 build
          (Since #120 )
        Took 1 min 20 sec.add descriptionError Messageexpected:<40> but was:<39>Stacktracejava.lang.AssertionError: expected:<40> but was:<39>
	at org.junit.Assert.fail(Assert.java:89)
	at org.junit.Assert.failNotEquals(Assert.java:835)
	at org.junit.Assert.assertEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:633)
	at org.nuxeo.importer.stream.tests.importer.TestAutomation.testFileBlobAndDocumentImport(TestAutomation.java:246) 

 Standard Output2020-05-06 22:48:39,948 [Nuxeo-ProducerPool-00] WARN  [AbstractCallablePool] Start Nuxeo-Producer Pool on 2 thread(s).
2020-05-06 22:48:39,949 [Nuxeo-Producer-00] INFO  [FileBlobMessageProducer] Producer using file list: /home/jenkins/agent/workspace/nuxeo_nuxeo_PR-3930/modules/platform/nuxeo-platform-importer/nuxeo-importer-stream/target-mongodb/test-classes/files/list.txt
2020-05-06 22:48:39,949 [Nuxeo-ProducerPool-00] INFO  [AbstractCallablePool] Pool is up and running
2020-05-06 22:48:39,949 [Nuxeo-Producer-01] INFO  [FileBlobMessageProducer] Producer using file list: /home/jenkins/agent/workspace/nuxeo_nuxeo_PR-3930/modules/platform/nuxeo-platform-importer/nuxeo-importer-stream/target-mongodb/test-classes/files/list.txt
2020-05-06 22:48:39,957 [Nuxeo-ProducerPool-00] INFO  [ArrayList] Producer 00 status: messages: 10, elapsed: 0.01s, throughput: 1250.00 msg/s.
2020-05-06 22:48:39,958 [Nuxeo-ProducerPool-00] INFO  [ArrayList] Producer 01 status: messages: 10, elapsed: 0.01s, throughput: 1250.00 msg/s.
2020-05-06 22:48:39,958 [Nuxeo-ProducerPool-00] WARN  [ProducerPool] Producers status: threads: 2, failures: 0, messages: 20, elapsed: 0.01s, throughput: 2500.00 msg/s
2020-05-06 22:48:39,960 [Nuxeo-Consumer-01-0-rebalance-revoked] INFO  [ConsumerPool] Creating consumer pool using Log subscribe on import/blob
2020-05-06 22:48:39,961 [Nuxeo-ConsumerPool-00] WARN  [AbstractCallablePool] Start Nuxeo-Consumer Pool on 2 thread(s).
2020-05-06 22:48:40,004 [Nuxeo-ConsumerPool-00] INFO  [AbstractCallablePool] Pool is up and running
2020-05-06 22:48:40,109 [Nuxeo-Consumer-00] INFO  [KafkaLogTailer] Rebalance assigned: [import-blob-03, import-blob-02, import-blob-01, import-blob-00]
2020-05-06 22:48:40,110 [Nuxeo-Consumer-01] INFO  [KafkaLogTailer] Rebalance assigned: [import-blob-07, import-blob-06, import-blob-05, import-blob-04]
2020-05-06 22:48:40,113 [Nuxeo-Consumer-00-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runBlobConsumers:import-blob-03|import-blob-02|import-blob-01|import-blob-00, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@771d06aa}] WARN  [ConsumerRunner] Rollback current batch because of consumer rebalancing
2020-05-06 22:48:40,113 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runBlobConsumers:import-blob-07|import-blob-06|import-blob-05|import-blob-04, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@771d06aa}] WARN  [ConsumerRunner] Rollback current batch because of consumer rebalancing
2020-05-06 22:48:40,113 [Nuxeo-Consumer-00-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runBlobConsumers:import-blob-03|import-blob-02|import-blob-01|import-blob-00, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@771d06aa}] INFO  [ConsumerRunner] Rebalance
2020-05-06 22:48:40,113 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runBlobConsumers:import-blob-07|import-blob-06|import-blob-05|import-blob-04, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@771d06aa}] INFO  [ConsumerRunner] Rebalance
2020-05-06 22:49:00,153 [Nuxeo-Consumer-01-7-video-000.mp4] INFO  [ConsumerRunner] No record after: 20s on KafkaLogTailer{id=StreamImporter-runBlobConsumers:import-blob-07|import-blob-06|import-blob-05|import-blob-04, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@771d06aa}, terminating
2020-05-06 22:49:00,153 [Nuxeo-Consumer-01-7-video-000.mp4] INFO  [ConsumerRunner] No more message on tailer: KafkaLogTailer{id=StreamImporter-runBlobConsumers:import-blob-07|import-blob-06|import-blob-05|import-blob-04, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@771d06aa}
2020-05-06 22:49:00,156 [Nuxeo-Consumer-01-7-video-000.mp4] INFO  [KafkaLogTailer] Rebalance revoked: [import-blob-07, import-blob-06, import-blob-05, import-blob-04]
2020-05-06 22:49:00,167 [Nuxeo-Consumer-00-11-text-001.txt] INFO  [ConsumerRunner] No record after: 20s on KafkaLogTailer{id=StreamImporter-runBlobConsumers:import-blob-03|import-blob-02|import-blob-01|import-blob-00, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@771d06aa}, terminating
2020-05-06 22:49:00,167 [Nuxeo-Consumer-00-11-text-001.txt] INFO  [ConsumerRunner] No more message on tailer: KafkaLogTailer{id=StreamImporter-runBlobConsumers:import-blob-03|import-blob-02|import-blob-01|import-blob-00, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@771d06aa}
2020-05-06 22:49:00,168 [Nuxeo-Consumer-00-11-text-001.txt] INFO  [KafkaLogTailer] Rebalance revoked: [import-blob-03, import-blob-02, import-blob-01, import-blob-00]
2020-05-06 22:49:00,171 [Nuxeo-ConsumerPool-00] INFO  [ArrayList] Consumer KafkaLogTailer{id=StreamImporter-runBlobConsumers:import-blob-03|import-blob-02|import-blob-01|import-blob-00, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@771d06aa} status: accepted (include retries): 12, committed: 12, batch: 2, batchFailure: 1, elapsed: 20.17s, throughput: 0.59 msg/s.
2020-05-06 22:49:00,171 [Nuxeo-ConsumerPool-00] INFO  [ArrayList] Consumer KafkaLogTailer{id=StreamImporter-runBlobConsumers:import-blob-07|import-blob-06|import-blob-05|import-blob-04, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@771d06aa} status: accepted (include retries): 8, committed: 8, batch: 1, batchFailure: 1, elapsed: 20.15s, throughput: 0.40 msg/s.
2020-05-06 22:49:00,171 [Nuxeo-ConsumerPool-00] WARN  [ConsumerPool] Consumers status: threads: 2, failure 0, messages committed: 20, elapsed: 20.17s, throughput: 0.99 msg/s
2020-05-06 22:49:00,173 [Nuxeo-ProducerPool-00] WARN  [AbstractCallablePool] Start Nuxeo-Producer Pool on 2 thread(s).
2020-05-06 22:49:00,174 [Nuxeo-ProducerPool-00] INFO  [AbstractCallablePool] Pool is up and running
2020-05-06 22:49:00,179 [Nuxeo-Producer-00] INFO  [RandomDocumentMessageProducer] RandomDocumentMessageProducer created, nbDocuments: 20
2020-05-06 22:49:00,179 [Nuxeo-Producer-01] INFO  [RandomDocumentMessageProducer] RandomDocumentMessageProducer created, nbDocuments: 20
2020-05-06 22:49:00,348 [Nuxeo-ProducerPool-00] INFO  [ArrayList] Producer 00 status: messages: 28, elapsed: 0.15s, throughput: 185.43 msg/s.
2020-05-06 22:49:00,348 [Nuxeo-ProducerPool-00] INFO  [ArrayList] Producer 01 status: messages: 62, elapsed: 0.17s, throughput: 356.32 msg/s.
2020-05-06 22:49:00,348 [Nuxeo-ProducerPool-00] WARN  [ProducerPool] Producers status: threads: 2, failures: 0, messages: 90, elapsed: 0.17s, throughput: 517.24 msg/s
2020-05-06 22:49:00,349 [Nuxeo-Consumer-01-0-rebalance-revoked] WARN  [DocumentConsumers] Import documents from log: import/doc into: test//, with policy: DocumentConsumerPolicy{blockIndexing=true, bulkMode=true, blockAsyncListeners=true, blockPostCommitListeners=true, blockDefaultSyncListeners=true, ConsumerPolicy{batchPolicy=BatchPolicy{capacity=10, threshold=PT5S}, retryPolicy=net.jodah.failsafe.RetryPolicy@3539cf45, skipFailure=false, waitMessageTimeout=PT20S, startOffset=LAST_COMMITTED, salted=true, name='StreamImporter/runDocumentConsumers', maxThreads=2}}
2020-05-06 22:49:00,350 [Nuxeo-Consumer-01-0-rebalance-revoked] INFO  [ConsumerPool] Creating consumer pool using Log subscribe on import/doc
2020-05-06 22:49:00,350 [Nuxeo-ConsumerPool-00] WARN  [AbstractCallablePool] Start Nuxeo-Consumer Pool on 2 thread(s).
2020-05-06 22:49:00,355 [Nuxeo-ConsumerPool-00] INFO  [AbstractCallablePool] Pool is up and running
2020-05-06 22:49:00,460 [Nuxeo-Consumer-01] INFO  [KafkaLogTailer] Rebalance assigned: [import-doc-02, import-doc-03]
2020-05-06 22:49:00,460 [Nuxeo-Consumer-00] INFO  [KafkaLogTailer] Rebalance assigned: [import-doc-00, import-doc-01]
2020-05-06 22:49:00,464 [Nuxeo-Consumer-00-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-01, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] WARN  [ConsumerRunner] Rollback current batch because of consumer rebalancing
2020-05-06 22:49:00,464 [Nuxeo-Consumer-00-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-01, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] INFO  [DocumentMessageConsumer] rollback
2020-05-06 22:49:00,465 [Nuxeo-Consumer-00-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-01, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] INFO  [ConsumerRunner] Rebalance
2020-05-06 22:49:20,355 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-02|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] WARN  [ConsumerRunner] Rollback current batch because of consumer rebalancing
2020-05-06 22:49:20,356 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-02|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] INFO  [DocumentMessageConsumer] rollback
2020-05-06 22:49:20,356 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-02|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] INFO  [ConsumerRunner] Rebalance
2020-05-06 22:49:21,625 [Nuxeo-Consumer-00-89-/01-idiosyncrasy-winsome-intentness/mugging] INFO  [ConsumerRunner] No record after: 20s on KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-01, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}, terminating
2020-05-06 22:49:21,627 [Nuxeo-Consumer-00-89-/01-idiosyncrasy-winsome-intentness/mugging] INFO  [ConsumerRunner] No more message on tailer: KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-01, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}
2020-05-06 22:49:21,628 [Nuxeo-Consumer-00-89-/01-idiosyncrasy-winsome-intentness/mugging] INFO  [KafkaLogTailer] Rebalance revoked: [import-doc-00, import-doc-01]
2020-05-06 22:49:22,463 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-02|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] INFO  [KafkaLogTailer] Rebalance revoked: [import-doc-02, import-doc-03]
2020-05-06 22:49:22,465 [Nuxeo-Consumer-01-0-rebalance-revoked] INFO  [KafkaLogTailer] Rebalance assigned: [import-doc-00, import-doc-02, import-doc-01, import-doc-03]
2020-05-06 22:49:40,356 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-02|import-doc-01|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] WARN  [ConsumerRunner] Rollback current batch because of consumer rebalancing
2020-05-06 22:49:40,356 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-02|import-doc-01|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] INFO  [DocumentMessageConsumer] rollback
2020-05-06 22:49:40,357 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-02|import-doc-01|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] INFO  [ConsumerRunner] Rebalance
2020-05-06 22:50:00,357 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-02|import-doc-01|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] INFO  [ConsumerRunner] No record after: 20s on KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-02|import-doc-01|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}, terminating
2020-05-06 22:50:00,359 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-02|import-doc-01|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] INFO  [ConsumerRunner] No more message on tailer: KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-02|import-doc-01|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}
2020-05-06 22:50:00,360 [Nuxeo-Consumer-01-0-rebalance-assigned-KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-02|import-doc-01|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694}] INFO  [KafkaLogTailer] Rebalance revoked: [import-doc-00, import-doc-02, import-doc-01, import-doc-03]
2020-05-06 22:50:00,363 [Nuxeo-ConsumerPool-00] INFO  [ArrayList] Consumer KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-01, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694} status: accepted (include retries): 90, committed: 90, batch: 10, batchFailure: 1, elapsed: 21.28s, throughput: 4.23 msg/s.
2020-05-06 22:50:00,363 [Nuxeo-ConsumerPool-00] INFO  [ArrayList] Consumer KafkaLogTailer{id=StreamImporter-runDocumentConsumers:import-doc-00|import-doc-02|import-doc-01|import-doc-03, closed=false, codec=org.nuxeo.lib.stream.codec.SerializableCodec@2eb29694} status: accepted (include retries): 0, committed: 0, batch: 1, batchFailure: 2, elapsed: 60.01s, throughput: 0.00 msg/s.
2020-05-06 22:50:00,363 [Nuxeo-ConsumerPool-00] WARN  [ConsumerPool] Consumers status: threads: 2, failure 0, messages committed: 90, elapsed: 60.01s, throughput: 1.50 msg/s