Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Intermittent failures in MongoDbTest.testTailingConsumer() and MongoDbTest.testPersistentTailingConsumer() #2658

Closed
ppalaga opened this issue May 24, 2021 · 4 comments · Fixed by #2746
Closed

Intermittent failures in MongoDbTest.testTailingConsumer() and MongoDbTest.testPersistentTailingConsumer() #2658

ppalaga opened this issue May 24, 2021 · 4 comments · Fixed by #2746
Assignees
@JiriOndrusek
Milestone
2.0.0-M2

Comments

@ppalaga
Copy link
Contributor

ppalaga commented May 24, 2021

I have seen this once on the CI and once locally (1 in ~6 attempts). I guess there is a race in how we read and write to the results collection. Maybe synchronizing on the list could help.

[INFO] Running org.apache.camel.quarkus.component.mongodb.it.MongodbGridfsTest
2021-05-24 15:50:14,342 INFO  [org.apa.cam.qua.com.mon.it.MongoDbTestResource] (pool-4-thread-1) TestcontainersConfiguration(userProperties={docker.client.strategy=org.testcontainers.dockerclient.UnixSocketClientProviderStrategy}, classpathProperties={}, environment={RUNNER_WORKSPACE=/home/runner/work/camel-quarkus, PATH=/opt/hostedtoolcache/jdk-11-hotspot/1.0.0/x64/bin:/home/linuxbrew/.linuxbrew/bin:/home/linuxbrew/.linuxbrew/sbin:/home/runner/.local/bin:/opt/pipx_bin:/usr/share/rust/.cargo/bin:/home/runner/.config/composer/vendor/bin:/usr/local/.ghcup/bin:/home/runner/.dotnet/tools:/snap/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin, INVOCATION_ID=462f0679e9ad49cfa37af8c70349be4e, GITHUB_REPOSITORY_OWNER=apache, SWIFT_PATH=/usr/share/swift/usr/bin, CHROMEWEBDRIVER=/usr/local/share/chrome_driver, GITHUB_WORKFLOW=Camel Quarkus CI, CONDA=/usr/share/miniconda, SELENIUM_JAR_PATH=/usr/share/java/selenium-server-standalone.jar, RUNNER_USER=runner, GITHUB_RUN_NUMBER=2374, ANDROID_HOME=/usr/local/lib/android/sdk, GITHUB_BASE_REF=main, PIPX_HOME=/opt/pipx, GITHUB_WORKSPACE=/home/runner/work/camel-quarkus/camel-quarkus, GITHUB_RETENTION_DAYS=90, JOURNAL_STREAM=9:19376, GITHUB_API_URL=https://api.github.com, GITHUB_PATH=/home/runner/work/_temp/_runner_file_commands/add_path_344a156e-71b7-4d6b-a822-eb5f6af5dfcb, GITHUB_EVENT_NAME=pull_request, *** GITHUB_JOB=native-tests, GITHUB_ACTIONS=true, CHROME_BIN=/usr/bin/google-chrome, DOTNET_MULTILEVEL_LOOKUP=0, HOMEBREW_CLEANUP_PERIODIC_FULL_DAYS=3650, AGENT_TOOLSDIRECTORY=/opt/hostedtoolcache, ANDROID_NDK_HOME=/usr/local/lib/android/sdk/ndk-bundle, ANDROID_NDK_ROOT=/usr/local/lib/android/sdk/ndk-bundle, VCPKG_INSTALLATION_ROOT=/usr/local/share/vcpkg, GITHUB_GRAPHQL_URL=https://api.github.com/graphql, HOMEBREW_CELLAR="/home/linuxbrew/.linuxbrew/Cellar", OLDPWD=/home/runner/work/camel-quarkus/camel-quarkus/integration-tests/mongodb, MAVEN_ARGS=-V -ntp -Dhttp.keepAlive=false -e, GITHUB_ENV=/home/runner/work/_temp/_runner_file_commands/set_env_344a156e-71b7-4d6b-a822-eb5f6af5dfcb, GRAALVM_11_ROOT=/usr/local/graalvm/graalvm-ce-java11-21.1.0, RUNNER_OS=Linux, GITHUB_EVENT_PATH=/home/runner/work/_temp/_github_workflow/event.json, DOTNET_NOLOGO=1, DEBIAN_FRONTEND=noninteractive, GITHUB_ACTION=run5, POWERSHELL_DISTRIBUTION_CHANNEL=GitHub-Actions-ubuntu20, GITHUB_ACTOR=ppalaga, RUNNER_TOOL_CACHE=/opt/hostedtoolcache, SHLVL=1, LEIN_HOME=/usr/local/lib/lein, PIPX_BIN_DIR=/opt/pipx_bin, GITHUB_SERVER_URL=https://github.com, JAVA_HOME=/opt/hostedtoolcache/jdk-11-hotspot/1.0.0/x64, GITHUB_REF=refs/pull/2643/merge, GECKOWEBDRIVER=/usr/local/share/gecko_driver, BOOTSTRAP_HASKELL_NONINTERACTIVE=1, GOROOT_1_14_X64=/opt/hostedtoolcache/go/1.14.15/x64, JAVA_HOME_8_X64=/usr/lib/jvm/adoptopenjdk-8-hotspot-amd64, LANG=en_US.UTF-8, HOMEBREW_PREFIX="/home/linuxbrew/.linuxbrew", GRADLE_HOME=/usr/share/gradle-7.0.2, MAVEN_OPTS= -Xmx3000m, ANT_HOME=/usr/share/ant, GITHUB_REPOSITORY=apache/camel-quarkus, GITHUB_ACTION_REF=, HOMEBREW_REPOSITORY="/home/linuxbrew/.linuxbrew/Homebrew", TESTCONTAINERS_RYUK_DISABLED=true, MAVEN_CMD_LINE_ARGS= -V -ntp -Dhttp.keepAlive=false -e clean verify -Dformatter.skip -Dimpsort.skip -Denforcer.skip -Pnative,docker,ci -Dquarkus.native.builder-image=quay.io/quarkus/ubi-quarkus-native-image:20.3.2-java11 -pl integration-tests/arangodb,integration-tests/debezium,integration-tests/cassandraql,integration-tests/couchdb,integration-tests/influxdb,integration-tests/jdbc,integration-tests/jpa,integration-tests/kudu,integration-tests/leveldb,integration-tests/minio,integration-tests/mongodb, _=./mvnw, AZURE_EXTENSION_DIR=/opt/az/azcliextensions, NVM_DIR=/home/runner/.nvm, ANDROID_NDK_LATEST_HOME=/usr/local/lib/android/sdk/ndk/22.1.7171670, DEPLOYMENT_BASEPATH=/opt/runner, CI=true, HOMEBREW_NO_AUTO_UPDATE=1, GITHUB_ACTION_REPOSITORY=, DOTNET_SKIP_FIRST_TIME_EXPERIENCE=1, LEIN_JAR=/usr/local/lib/lein/self-installs/leiningen-2.9.6-standalone.jar, MAVEN_PROJECTBASEDIR=/home/runner/work/camel-quarkus/camel-quarkus, ANDROID_SDK_ROOT=/usr/local/lib/android/sdk, GITHUB_RUN_ID=871616263, GOROOT_1_16_X64=/opt/hostedtoolcache/go/1.16.4/x64, USER=runner, XDG_CONFIG_HOME=/home/runner/.config, GITHUB_SHA=dcc63c312850ee9eb276548c3052fa1790ccc97f, ImageOS=ubuntu20, ImageVersion=20210517.1, ACCEPT_EULA=Y, RUNNER_TEMP=/home/runner/work/_temp, GITHUB_HEAD_REF=210521-camel-main, RUNNER_PERFLOG=/home/runner/perflog, GOROOT_1_15_X64=/opt/hostedtoolcache/go/1.15.12/x64, JAVA_HOME_11_X64=/usr/lib/jvm/adoptopenjdk-11-hotspot-amd64, PERFLOG_LOCATION_SETTING=RUNNER_PERFLOG, RUNNER_TRACKING_ID=github_6db3cdaf-960c-4d7a-baf4-5111afc9798a, HOME=/home/runner})
2021-05-24 15:50:14,370 INFO  [org.tes.doc.DockerClientProviderStrategy] (pool-4-thread-1) Loaded org.testcontainers.dockerclient.UnixSocketClientProviderStrategy from ~/.testcontainers.properties, will try it first
2021-05-24 15:50:15,228 INFO  [org.tes.doc.DockerClientProviderStrategy] (pool-4-thread-1) Found Docker environment with local Unix socket (unix:///var/run/docker.sock)
2021-05-24 15:50:15,229 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) Docker host IP address is localhost
2021-05-24 15:50:15,282 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) Connected to docker: 
  Server Version: 20.10.6+azure
  API Version: 1.41
  Operating System: Ubuntu 20.04.2 LTS
  Total Memory: 6954 MB
2021-05-24 15:50:15,282 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) Checking the system...
2021-05-24 15:50:15,283 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) ✔︎ Docker server version should be at least 1.6.0
2021-05-24 15:50:15,284 INFO  [org.tes.uti.ImageNameSubstitutor] (pool-4-thread-1) Image name substitution will be performed by: DefaultImageNameSubstitutor (composite of 'ConfigurationFileImageNameSubstitutor' and 'PrefixingImageNameSubstitutor')
2021-05-24 15:50:15,966 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) ✔︎ Docker environment should have more than 2GB free disk space
2021-05-24 15:50:16,152 INFO  [🐳 .0]] (pool-4-thread-1) Pulling docker image: mongo:4.0. Please be patient; this may take some time but only needs to be done once.
2021-05-24 15:50:16,433 INFO  [🐳 .0]] (docker-java-stream--1320945667) Starting to pull image
2021-05-24 15:50:16,455 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  0 pending,  0 downloaded,  0 extracted, (0 bytes/0 bytes)
2021-05-24 15:50:16,682 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers: 12 pending,  1 downloaded,  0 extracted, (609 bytes/? MB)
2021-05-24 15:50:16,734 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers: 11 pending,  2 downloaded,  0 extracted, (44 KB/? MB)
2021-05-24 15:50:16,752 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers: 10 pending,  3 downloaded,  0 extracted, (44 KB/? MB)
2021-05-24 15:50:16,768 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  9 pending,  4 downloaded,  0 extracted, (44 KB/? MB)
2021-05-24 15:50:16,831 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  8 pending,  5 downloaded,  0 extracted, (46 KB/? MB)
2021-05-24 15:50:16,848 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  7 pending,  6 downloaded,  0 extracted, (46 KB/? MB)
2021-05-24 15:50:16,872 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  7 pending,  6 downloaded,  1 extracted, (46 KB/? MB)
2021-05-24 15:50:16,935 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  6 pending,  7 downloaded,  1 extracted, (565 KB/? MB)
2021-05-24 15:50:16,964 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  5 pending,  8 downloaded,  1 extracted, (569 KB/? MB)
2021-05-24 15:50:17,337 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  5 pending,  8 downloaded,  2 extracted, (16 MB/? MB)
2021-05-24 15:50:17,720 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  5 pending,  8 downloaded,  3 extracted, (48 MB/? MB)
2021-05-24 15:50:17,880 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  5 pending,  8 downloaded,  4 extracted, (60 MB/? MB)
2021-05-24 15:50:18,028 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  5 pending,  8 downloaded,  5 extracted, (67 MB/? MB)
2021-05-24 15:50:18,183 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  5 pending,  8 downloaded,  6 extracted, (86 MB/? MB)
2021-05-24 15:50:18,293 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  4 pending,  9 downloaded,  6 extracted, (95 MB/? MB)
2021-05-24 15:50:22,321 INFO  [🐳 .0]] (docker-java-stream--1320945667) Pulling image layers:  4 pending,  9 downloaded,  7 extracted, (105 MB/? MB)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at io.quarkus.test.junit.QuarkusTestExtension.runExtensionMethod(QuarkusTestExtension.java:992)
	at io.quarkus.test.junit.QuarkusTestExtension.interceptTestMethod(QuarkusTestExtension.java:869)
	at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
	at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:149)
	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:140)
	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:84)
	at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)
	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104)
	at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$6(TestMethodTestDescriptor.java:210)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:206)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:131)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:65)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:51)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:108)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:88)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:54)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:67)
	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:52)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:96)
	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:75)
	at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invokeAllTests(JUnitPlatformProvider.java:150)
	at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invoke(JUnitPlatformProvider.java:124)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
@ppalaga ppalaga added this to the 2.0.0 milestone May 24, 2021
@JiriOndrusek
Copy link
Contributor

@ppalaga
It seems, like the container didn't start correctly.

Here is my local log

2021-05-25 11:20:07,097 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) ✔︎ Docker environment should have more than 2GB free disk space
2021-05-25 11:20:07,107 INFO  [🐳 .0]] (pool-4-thread-1) Creating container for image: mongo:4.0
2021-05-25 11:20:07,459 INFO  [🐳 .0]] (pool-4-thread-1) Starting container with ID: 4dcfebda5b25af00058f8dfe7045644521dd6e575d85afff0fbb44abe5f86287
2021-05-25 11:20:07,979 INFO  [🐳 .0]] (pool-4-thread-1) Container mongo:4.0 is starting: 4dcfebda5b25af00058f8dfe7045644521dd6e575d85afff0fbb44abe5f86287
2021-05-25 11:20:09,195 INFO  [🐳 .0]] (pool-4-thread-1) Container mongo:4.0 started in PT2.097561S
2021-05-25 11:20:09,972 INFO  [org.mon.dri.cluster] (pool-4-thread-1) Cluster created with settings {hosts=[localhost:49154], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-05-25 11:20:10,015 INFO  [org.mon.dri.cluster] (pool-4-thread-1) Cluster description not yet available. Waiting for 30000 ms before timing out
2021-05-25 11:20:10,035 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60acc14961fda01911b47ca5', description='null'}-localhost:49154) Opened connection [connectionId{localValue:2, serverValue:6}] to localhost:49154
2021-05-25 11:20:10,035 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60acc14961fda01911b47ca5', description='null'}-localhost:49154) Opened connection [connectionId{localValue:1, serverValue:5}] to localhost:49154
2021-05-25 11:20:10,044 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60acc14961fda01911b47ca5', description='null'}-localhost:49154) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49154, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=21143267, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=null, lastWriteDate=Tue May 25 11:20:09 CEST 2021, lastUpdateTimeNanos=8563393016415}

As you can see, there are messages about started container right after line ✔︎ Docker environment should have more than 2GB free disk space. But in the log with an error, there is an error right instead. The only explanation is that container configuration can make this container to intermittently fail. (which surprises me, because almost the same configuration is used for debezium-mongodb test. I'll try to investigate it.

@ppalaga
Copy link
Contributor Author

ppalaga commented May 25, 2021

Ups, sorry, the log I pasted isn't for MongoDbTest.testTailingConsumer() - the issue I refer to was failing on Awaitility timing out.

JiriOndrusek added a commit to JiriOndrusek/camel-quarkus that referenced this issue May 25, 2021
@JiriOndrusek
Quick fix - Intermittent failures in MongoDbTest.testTailingConsumer() …
f971e01 
…apache#2658
@JiriOndrusek JiriOndrusek mentioned this issue May 25, 2021
Merged
@JiriOndrusek
Copy link
Contributor

There is also an exception (, which doesn't cause failure), when test is stopped. Probably wrong order of stopping container image and routes. It would be nice to fix that too.

ppalaga pushed a commit that referenced this issue May 25, 2021
@JiriOndrusek @ppalaga
Quick fix - Intermittent failures in MongoDbTest.testTailingConsumer() …
8ce5068 
…#2658
jamesnetherton pushed a commit to jboss-fuse/camel-quarkus that referenced this issue May 27, 2021
@JiriOndrusek @jamesnetherton
Quick fix - Intermittent failures in MongoDbTest.testTailingConsumer() …
a5afa9a 
…apache#2658
jamesnetherton pushed a commit to jboss-fuse/camel-quarkus that referenced this issue May 27, 2021
@JiriOndrusek @jamesnetherton
Quick fix - Intermittent failures in MongoDbTest.testTailingConsumer() …
be4fb81 
…apache#2658
ppalaga added a commit to ppalaga/camel-quarkus that referenced this issue Jun 4, 2021
@ppalaga
Fixup 8ce5068 Intermittent failures in MongoDbTest.testTailingConsume…
50f5453 
…r() apache#2658
ppalaga added a commit to ppalaga/camel-quarkus that referenced this issue Jun 6, 2021
@ppalaga
Fixup 8ce5068 Intermittent failures in MongoDbTest.testTailingConsume…
2fc6b8d 
…r() apache#2658
@ppalaga
Copy link
Contributor Author

ppalaga commented Jun 7, 2021

Disabling MongoDbTest.testTailingConsumer() and MongoDbTest.testPersistentTailingConsumer(). The failures occurred in ~50% of runs for me.

The output when testTailingConsumer() is disabled and testPersistentTailingConsumer() is enabled:

[INFO] Running org.apache.camel.quarkus.component.mongodb.it.MongoDbTest
2021-06-07 11:33:41,761 INFO  [org.apa.cam.qua.com.mon.it.MongoDbTestResource] (pool-4-thread-1) TestcontainersConfiguration(userProperties={docker.client.strategy=org.testcontainers.dockerclient.EnvironmentAndSystemPropertyClientProviderStrategy}, classpathProperties={}, environment={PATH=/home/ppalaga/gems/bin:/home/ppalaga/orgs/graalvm/mx:/home/ppalaga/bin/async-profiler-1.6-linux-x64:/home/ppalaga/bin/vscode-installations/code/bin:/home/ppalaga/.yarn/bin:/home/ppalaga/.config/yarn/global/node_modules/.bin:/home/ppalaga/bin:/home/ppalaga/bin/gradle-3.5.x/bin:/home/ppalaga/gems/bin:/home/ppalaga/.sdkman/candidates/mvnd/current/bin:/home/ppalaga/.sdkman/candidates/maven/current/bin:/home/ppalaga/.sdkman/candidates/jbang/current/bin:/home/ppalaga/.sdkman/candidates/jbake/current/bin:/home/ppalaga/.sdkman/candidates/java/current/bin:/home/ppalaga/orgs/graalvm/mx:/home/ppalaga/bin/async-profiler-1.6-linux-x64:/home/ppalaga/bin/vscode-installations/code/bin:/home/ppalaga/.yarn/bin:/home/ppalaga/.config/yarn/global/node_modules/.bin:/home/ppalaga/bin:/home/ppalaga/bin/gradle-3.5.x/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin, INVOCATION_ID=91cf6a0b3e6545bba8bbfe4dd01c306b, XAUTHORITY=/run/user/1000/xauth_gXOUKd, SDKMAN_VERSION=5.11.5+713, HISTCONTROL=ignoredups, XDG_DATA_DIRS=/home/ppalaga/.local/share/flatpak/exports/share:/var/lib/flatpak/exports/share:/usr/local/share:/usr/share, DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus, ANDROID_HOME=/home/ppalaga/bin/android/android-sdk, XDG_CURRENT_DESKTOP=KDE, JOURNAL_STREAM=8:22148, QT_AUTO_SCREEN_SCALE_FACTOR=0, MAVEN_HOME=/home/ppalaga/bin/maven/apache-maven-3.6.x, MAIL=/var/spool/mail/ppalaga, SSH_AGENT_PID=3189, SDKMAN_DIR=/home/ppalaga/.sdkman, GRAALVM_HOME=/home/ppalaga/.sdkman/candidates/java/21.1.0.r11-grl, SESSION_MANAGER=local/unix:@/tmp/.ICE-unix/3268,unix/unix:/tmp/.ICE-unix/3268, LOGNAME=ppalaga, JBANG_EDITOR=code, MANAGERPID=3118, PWD=/home/ppalaga/orgs/cq/camel-quarkus/integration-tests/mongodb, XCURSOR_THEME=breeze_cursors, LANGUAGE=en_US, KDE_SESSION_VERSION=5, LESSOPEN=||/usr/bin/lesspipe.sh %s, SHELL=/bin/bash, SDKMAN_CANDIDATES_API=https://api.sdkman.io/2, ECLIPSE_WORKSPACE=/home/ppalaga/orgs/cq, OLDPWD=/home/ppalaga/orgs/cq/camel-quarkus/integration-tests/mongodb, GEM_HOME=/home/ppalaga/gems, KDE_FULL_SESSION=true, SSH_ASKPASS=/usr/bin/ksshaskpass, XDG_SESSION_PATH=/org/freedesktop/DisplayManager/Session0, FG_AIRCRAFT=/home/ppalaga/FlightGear/Aircraft, MVND_HOME=/home/ppalaga/.sdkman/candidates/mvnd/current, SYSTEMD_EXEC_PID=3412, LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=01;37;41:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.zst=01;31:*.tzst=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.wim=01;31:*.swm=01;31:*.dwm=01;31:*.esd=01;31:*.jpg=01;35:*.jpeg=01;35:*.mjpg=01;35:*.mjpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.webp=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=01;36:*.au=01;36:*.flac=01;36:*.m4a=01;36:*.mid=01;36:*.midi=01;36:*.mka=01;36:*.mp3=01;36:*.mpc=01;36:*.ogg=01;36:*.ra=01;36:*.wav=01;36:*.oga=01;36:*.opus=01;36:*.spx=01;36:*.xspf=01;36:, XDG_SESSION_DESKTOP=KDE, SHLVL=2, FG_SCENERY=/home/ppalaga/FlightGear/Scenery, KDE_APPLICATIONS_AS_SCOPE=1, OXYGEN_DISABLE_INNER_SHADOWS_HACK=1, HISTSIZE=100000, SDKMAN_OLD_PWD=/home/ppalaga/orgs/cq/camel-quarkus/integration-tests/mongodb, JAVA_HOME=/usr/lib/jvm/java-11-openjdk, BASH_FUNC_which%%=() {  ( alias;
 eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot "$@"
}, JBANG_HOME=/home/ppalaga/.sdkman/candidates/jbang/current, TERM=xterm, KDE_SESSION_UID=1000, XDG_CONFIG_DIRS=/etc/xdg:/usr/share/kde-settings/kde-profile/default/xdg, XDG_SEAT_PATH=/org/freedesktop/DisplayManager/Seat0, LANG=en_IE.UTF-8, XDG_SESSION_ID=1, MOZ_GMP_PATH=/usr/lib64/mozilla/plugins/gmp-gmpopenh264/system-installed, XDG_SESSION_TYPE=x11, HISTFILESIZE=100000, DISPLAY=:0, GTK_RC_FILES=/etc/gtk/gtkrc:/home/ppalaga/.gtkrc:/home/ppalaga/.config/gtkrc, which_declare=declare -f, ECLIPSE_HOME=/home/ppalaga/bin/eclipse-installations/java-latest/eclipse, MAVEN_CMD_LINE_ARGS= -DtrimStackTrace=false --no-snapshot-updates clean test, _=/usr/lib/jvm/java-11-openjdk-11.0.11.0.9-2.fc34.x86_64/bin/java, XDG_SESSION_CLASS=user, SDKMAN_CANDIDATES_DIR=/home/ppalaga/.sdkman/candidates, JBAKE_HOME=/home/ppalaga/.sdkman/candidates/jbake/current, XCURSOR_SIZE=24, LIBOVERLAY_SCROLLBAR=0, GDK_CORE_DEVICE_EVENTS=1, DESKTOP_SESSION=/usr/share/xsessions/plasmax11, MAVEN_PROJECTBASEDIR=/home/ppalaga/orgs/cq/camel-quarkus, SDKMAN_PLATFORM=linuxx64, USER=ppalaga, GTK2_RC_FILES=/etc/gtk-2.0/gtkrc:/home/ppalaga/.gtkrc-2.0:/home/ppalaga/.gtkrc-2.0-kde4:/home/ppalaga/.config/gtkrc-2.0, XDG_MENU_PREFIX=kf5-, XDG_SEAT=seat0, SSH_AUTH_SOCK=/tmp/ssh-XXXXXXbSzAX2/agent.3133, EDITOR=/home/ppalaga/bin/nano-ansi.sh, PK_OFFLINE_UPDATE=1, GTK_OVERLAY_SCROLLING=0, HOSTNAME=terpistone, KDEDIRS=/usr, XDG_RUNTIME_DIR=/run/user/1000, XDG_VTNR=2, HOME=/home/ppalaga})
2021-06-07 11:33:41,794 INFO  [org.tes.doc.DockerClientProviderStrategy] (pool-4-thread-1) Loaded org.testcontainers.dockerclient.EnvironmentAndSystemPropertyClientProviderStrategy from ~/.testcontainers.properties, will try it first
2021-06-07 11:33:42,195 INFO  [org.tes.doc.DockerClientProviderStrategy] (pool-4-thread-1) Found Docker environment with Environment variables, system properties and defaults. Resolved dockerHost=unix:///var/run/docker.sock
2021-06-07 11:33:42,196 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) Docker host IP address is localhost
2021-06-07 11:33:42,228 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) Connected to docker: 
  Server Version: 20.10.6
  API Version: 1.41
  Operating System: Fedora 34 (KDE Plasma)
  Total Memory: 64247 MB
2021-06-07 11:33:42,231 INFO  [org.tes.uti.ImageNameSubstitutor] (pool-4-thread-1) Image name substitution will be performed by: DefaultImageNameSubstitutor (composite of 'ConfigurationFileImageNameSubstitutor' and 'PrefixingImageNameSubstitutor')
2021-06-07 11:33:42,271 INFO  [org.tes.uti.RegistryAuthLocator] (pool-4-thread-1) Failure when attempting to lookup auth config. Please ignore if you don't have images in an authenticated registry. Details: (dockerImageName: testcontainers/ryuk:0.3.1, configFile: /home/ppalaga/.docker/config.json. Falling back to docker-java default behaviour. Exception message: /home/ppalaga/.docker/config.json (No such file or directory)
2021-06-07 11:33:42,732 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) Ryuk started - will monitor and terminate Testcontainers containers on JVM exit
2021-06-07 11:33:42,732 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) Checking the system...
2021-06-07 11:33:42,733 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) ✔︎ Docker server version should be at least 1.6.0
2021-06-07 11:33:42,817 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) ✔︎ Docker environment should have more than 2GB free disk space
2021-06-07 11:33:42,849 INFO  [🐳 .4]] (pool-4-thread-1) Creating container for image: mongo:4.4
2021-06-07 11:33:43,108 INFO  [🐳 .4]] (pool-4-thread-1) Starting container with ID: f7247c51447f301cf13994fc0ae4c07add4fdfbaff88f011477add7d1d63ad86
2021-06-07 11:33:43,496 INFO  [🐳 .4]] (pool-4-thread-1) Container mongo:4.4 is starting: f7247c51447f301cf13994fc0ae4c07add4fdfbaff88f011477add7d1d63ad86
2021-06-07 11:33:44,690 INFO  [🐳 .4]] (pool-4-thread-1) Container mongo:4.4 started in PT1.872502S
2021-06-07 11:33:45,417 INFO  [org.mon.dri.cluster] (pool-4-thread-1) Cluster created with settings {hosts=[localhost:49178], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:33:45,449 INFO  [org.mon.dri.cluster] (pool-4-thread-1) Cluster description not yet available. Waiting for 30000 ms before timing out
2021-06-07 11:33:45,470 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde7f94aca2c50b911ab95', description='null'}-localhost:49178) Opened connection [connectionId{localValue:2, serverValue:5}] to localhost:49178
2021-06-07 11:33:45,470 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde7f94aca2c50b911ab95', description='null'}-localhost:49178) Opened connection [connectionId{localValue:1, serverValue:6}] to localhost:49178
2021-06-07 11:33:45,478 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde7f94aca2c50b911ab95', description='null'}-localhost:49178) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49178, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=18507045, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde7f7713c9e9d5ac97dc2, counter=6}, lastWriteDate=Mon Jun 07 11:33:45 CEST 2021, lastUpdateTimeNanos=7814680973127}
2021-06-07 11:33:45,492 INFO  [org.mon.dri.connection] (pool-4-thread-1) Opened connection [connectionId{localValue:3, serverValue:7}] to localhost:49178
2021-06-07 11:33:45,587 INFO  [org.mon.dri.connection] (pool-4-thread-1) Closed connection [connectionId{localValue:3, serverValue:7}] to localhost:49178 because the pool has been closed.
2021-06-07 11:33:46,032 INFO  [org.mon.dri.cluster] (main) Cluster created with settings {hosts=[localhost:49178], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:33:46,036 INFO  [org.mon.dri.cluster] (main) Cluster created with settings {hosts=[localhost:49178], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:33:46,037 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde7fa4aca2c50b911ab96', description='null'}-localhost:49178) Opened connection [connectionId{localValue:4, serverValue:9}] to localhost:49178
2021-06-07 11:33:46,036 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde7fa4aca2c50b911ab96', description='null'}-localhost:49178) Opened connection [connectionId{localValue:5, serverValue:8}] to localhost:49178
2021-06-07 11:33:46,038 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde7fa4aca2c50b911ab96', description='null'}-localhost:49178) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49178, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=2058125, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde7f7713c9e9d5ac97dc2, counter=6}, lastWriteDate=Mon Jun 07 11:33:45 CEST 2021, lastUpdateTimeNanos=7815248267066}
2021-06-07 11:33:46,047 INFO  [org.mon.dri.cluster] (main) Cluster created with settings {hosts=[localhost:49178], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:33:46,048 INFO  [org.mon.dri.cluster] (main) Cluster created with settings {hosts=[localhost:49178], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:33:46,052 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde7fa4aca2c50b911ab98', description='null'}-localhost:49178) Opened connection [connectionId{localValue:9, serverValue:13}] to localhost:49178
2021-06-07 11:33:46,052 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde7fa4aca2c50b911ab98', description='null'}-localhost:49178) Opened connection [connectionId{localValue:8, serverValue:12}] to localhost:49178
2021-06-07 11:33:46,053 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde7fa4aca2c50b911ab98', description='null'}-localhost:49178) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49178, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=2865573, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde7f7713c9e9d5ac97dc2, counter=6}, lastWriteDate=Mon Jun 07 11:33:45 CEST 2021, lastUpdateTimeNanos=7815263682401}
2021-06-07 11:33:46,054 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde7fa4aca2c50b911ab99', description='null'}-localhost:49178) Opened connection [connectionId{localValue:11, serverValue:15}] to localhost:49178
2021-06-07 11:33:46,054 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde7fa4aca2c50b911ab97', description='null'}-localhost:49178) Opened connection [connectionId{localValue:7, serverValue:10}] to localhost:49178
2021-06-07 11:33:46,055 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde7fa4aca2c50b911ab99', description='null'}-localhost:49178) Opened connection [connectionId{localValue:10, serverValue:14}] to localhost:49178
2021-06-07 11:33:46,056 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde7fa4aca2c50b911ab99', description='null'}-localhost:49178) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49178, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=4154442, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde7f7713c9e9d5ac97dc2, counter=6}, lastWriteDate=Mon Jun 07 11:33:45 CEST 2021, lastUpdateTimeNanos=7815266711173}
2021-06-07 11:33:46,058 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde7fa4aca2c50b911ab97', description='null'}-localhost:49178) Opened connection [connectionId{localValue:6, serverValue:11}] to localhost:49178
2021-06-07 11:33:46,059 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde7fa4aca2c50b911ab97', description='null'}-localhost:49178) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49178, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=7661409, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde7f7713c9e9d5ac97dc2, counter=6}, lastWriteDate=Mon Jun 07 11:33:45 CEST 2021, lastUpdateTimeNanos=7815268976109}
2021-06-07 11:33:46,124 INFO  [org.apa.cam.qua.cor.CamelBootstrapRecorder] (main) Bootstrap runtime: org.apache.camel.quarkus.main.CamelMainRuntime
2021-06-07 11:33:46,240 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (main) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=tailingCollection&database=test&tailTrackIncreasingField=increasing
2021-06-07 11:33:46,246 INFO  [org.mon.dri.connection] (main) Opened connection [connectionId{localValue:12, serverValue:16}] to localhost:49178
2021-06-07 11:33:46,256 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (main) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=persistentTailingCollection&database=test&persistentId=darwin&persistentTailTracking=true&tailTrackIncreasingField=increasing
2021-06-07 11:33:46,258 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (main) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=streamChangesCollection&consumerType=changeStreams&database=test
2021-06-07 11:33:46,269 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Starting MongoDB Tailable Cursor consumer, binding to collection: db: com.mongodb.client.internal.MongoDatabaseImpl@434b120b, col: tailingCollection
2021-06-07 11:33:46,343 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Starting MongoDB Tailable Cursor consumer, binding to collection: db: com.mongodb.client.internal.MongoDatabaseImpl@48cec770, col: persistentTailingCollection
2021-06-07 11:33:46,379 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main) Routes startup summary (total:3 started:3)
2021-06-07 11:33:46,379 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Started route1 (mongodb://camelMongoClient)
2021-06-07 11:33:46,379 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Started persistentTailingCollection (mongodb://camelMongoClient)
2021-06-07 11:33:46,379 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Started route2 (mongodb://camelMongoClient)
2021-06-07 11:33:46,379 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main) Apache Camel 3.10.0 (camel-1) started in 200ms (build:0ms init:82ms start:118ms)
2021-06-07 11:33:46,511 INFO  [io.quarkus] (main) Quarkus 2.0.0.CR3 on JVM started in 6.083s. Listening on: http://localhost:41839
2021-06-07 11:33:46,512 INFO  [io.quarkus] (main) Profile test activated. 
2021-06-07 11:33:46,512 INFO  [io.quarkus] (main) Installed features: [camel-core, camel-mongodb, camel-mongodb-gridfs, camel-support-common, camel-support-mongodb, cdi, mongodb-client, resteasy, resteasy-jsonb, smallrye-context-propagation]
2021-06-07 11:33:46,526 INFO  [org.mon.dri.cluster] (main) Cluster created with settings {hosts=[localhost:49178], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:33:46,538 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde7fa4aca2c50b911ab9b', description='null'}-localhost:49178) Opened connection [connectionId{localValue:13, serverValue:17}] to localhost:49178
2021-06-07 11:33:46,538 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde7fa4aca2c50b911ab9b', description='null'}-localhost:49178) Opened connection [connectionId{localValue:14, serverValue:18}] to localhost:49178
2021-06-07 11:33:46,539 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde7fa4aca2c50b911ab9b', description='null'}-localhost:49178) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49178, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=10563973, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde7f7713c9e9d5ac97dc2, counter=6}, lastWriteDate=Mon Jun 07 11:33:46 CEST 2021, lastUpdateTimeNanos=7815750187023}
2021-06-07 11:33:46,905 INFO  [org.mon.dri.connection] (main) Opened connection [connectionId{localValue:15, serverValue:19}] to localhost:49178
2021-06-07 11:33:47,288 INFO  [org.mon.dri.connection] (Camel (camel-1) thread #0 - mongodb://camelMongoClient) Opened connection [connectionId{localValue:16, serverValue:20}] to localhost:49178
2021-06-07 11:33:47,456 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=outputTypeDocumentList&database=test&dynamicity=true&operation=findAll&outputType=DocumentList
2021-06-07 11:33:48,545 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=outputTypeDocument&database=test&dynamicity=true&operation=findOneByQuery&outputType=Document
2021-06-07 11:33:50,294 INFO  [org.mon.dri.connection] (Camel (camel-1) thread #0 - mongodb://camelMongoClient) Opened connection [connectionId{localValue:17, serverValue:21}] to localhost:49178
2021-06-07 11:33:54,229 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=camelMongoClientCamelTest&database=test&dynamicity=true&operation=insert
2021-06-07 11:33:54,277 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=camelMongoClientCamelTest&database=test&dynamicity=true&operation=findAll&outputType=MongoIterable
2021-06-07 11:33:54,320 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://myMongoClient?collection=myMongoClientCamelTest&database=test&dynamicity=true&operation=insert
2021-06-07 11:33:54,322 INFO  [org.mon.dri.connection] (executor-thread-0) Opened connection [connectionId{localValue:18, serverValue:22}] to localhost:49178
2021-06-07 11:33:54,355 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://myMongoClient?collection=myMongoClientCamelTest&database=test&dynamicity=true&operation=findAll&outputType=MongoIterable
2021-06-07 11:33:54,371 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=dynamicCamelTest&database=test&dynamicity=true&operation=insert
2021-06-07 11:33:54,429 INFO  [org.mon.dri.connection] (main) Closed connection [connectionId{localValue:15, serverValue:19}] to localhost:49178 because the pool has been closed.
[ERROR] Tests run: 10, Failures: 0, Errors: 1, Skipped: 1, Time elapsed: 16.338 s <<< FAILURE! - in org.apache.camel.quarkus.component.mongodb.it.MongoDbTest
[ERROR] testPersistentTailingConsumer  Time elapsed: 5.538 s  <<< ERROR!
org.awaitility.core.ConditionTimeoutException: Lambda expression in org.apache.camel.quarkus.component.mongodb.it.MongoDbTest that uses java.lang.String: expected the predicate to return <true> but it returned <false> for input of <{size=0}> within 5 seconds.
        at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:166)
        at org.awaitility.core.AbstractHamcrestCondition.await(AbstractHamcrestCondition.java:86)
        at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:939)
        at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:645)
        at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:662)
        at org.apache.camel.quarkus.component.mongodb.it.MongoDbTest.waitForTailingResults(MongoDbTest.java:283)
        at org.apache.camel.quarkus.component.mongodb.it.MongoDbTest.testPersistentTailingConsumer(MongoDbTest.java:171)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.quarkus.test.junit.QuarkusTestExtension.runExtensionMethod(QuarkusTestExtension.java:993)
        at io.quarkus.test.junit.QuarkusTestExtension.interceptTestMethod(QuarkusTestExtension.java:870)
        at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
        at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
        at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:149)
        at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:140)
        at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:84)
        at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
        at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)
        at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104)
        at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$6(TestMethodTestDescriptor.java:210)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:206)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:131)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:65)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
        at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
        at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
        at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
        at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
        at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
        at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
        at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
        at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32)
        at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
        at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:51)
        at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:108)
        at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:88)
        at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:54)
        at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:67)
        at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:52)
        at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:96)
        at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:75)
        at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invokeAllTests(JUnitPlatformProvider.java:150)
        at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invoke(JUnitPlatformProvider.java:124)
        at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
        at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
        at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
        at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)

[INFO] Running org.apache.camel.quarkus.component.mongodb.it.MongodbGridfsTest
2021-06-07 11:33:54,449 INFO  [org.apa.cam.com.mon.gri.GridFsEndpoint] (executor-thread-0) Initialize GridFS endpoint: mongodb-gridfs://camelMongoClient?database=test&operation=create
2021-06-07 11:33:54,563 INFO  [org.apa.cam.com.mon.gri.GridFsEndpoint] (executor-thread-0) Initialize GridFS endpoint: mongodb-gridfs://camelMongoClient?database=test&operation=findOne
2021-06-07 11:33:54,580 INFO  [org.apa.cam.com.mon.gri.GridFsEndpoint] (executor-thread-0) Initialize GridFS endpoint: mongodb-gridfs://camelMongoClient?database=test&operation=remove
2021-06-07 11:33:54,611 INFO  [org.apa.cam.com.mon.gri.GridFsEndpoint] (executor-thread-0) Initialize GridFS endpoint: mongodb-gridfs://myMongoClient?database=test&operation=create
2021-06-07 11:33:54,626 INFO  [org.apa.cam.com.mon.gri.GridFsEndpoint] (executor-thread-0) Initialize GridFS endpoint: mongodb-gridfs://myMongoClient?database=test&operation=findOne
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.174 s - in org.apache.camel.quarkus.component.mongodb.it.MongodbGridfsTest
2021-06-07 11:33:54,681 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main) Apache Camel 3.10.0 (camel-1) shutting down
2021-06-07 11:33:54,684 INFO  [org.apa.cam.com.mon.MongoDbChangeStreamsThread] (main) Stopping MongoDB Tailable Cursor consumer, bound to collection: db: test, col: streamChangesCollection
2021-06-07 11:33:54,685 INFO  [org.apa.cam.com.mon.MongoDbChangeStreamsThread] (main) Going to wait for stopping
2021-06-07 11:33:55,274 WARN  [org.apa.cam.com.mon.MongoDbChangeStreamsThread] (Camel (camel-1) thread #2 - mongodb://camelMongoClient) Exception from consuming from MongoDB caused by Attempted to decrement the reference count below 0. ConsumerThread will be stopped.: com.mongodb.MongoException: Attempted to decrement the reference count below 0
        at com.mongodb.MongoException.fromThrowableNonNull(MongoException.java:83)
        at com.mongodb.internal.operation.ChangeStreamBatchCursor.resumeableOperation(ChangeStreamBatchCursor.java:185)
        at com.mongodb.internal.operation.ChangeStreamBatchCursor.hasNext(ChangeStreamBatchCursor.java:64)
        at com.mongodb.client.internal.MongoChangeStreamCursorImpl.hasNext(MongoChangeStreamCursorImpl.java:58)
        at org.apache.camel.component.mongodb.MongoDbChangeStreamsThread.doRun(MongoDbChangeStreamsThread.java:72)
        at org.apache.camel.component.mongodb.MongoAbstractConsumerThread.run(MongoAbstractConsumerThread.java:70)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.IllegalStateException: Attempted to decrement the reference count below 0
        at com.mongodb.internal.binding.AbstractReferenceCounted.release(AbstractReferenceCounted.java:39)
        at com.mongodb.internal.binding.ClusterBinding$ClusterBindingConnectionSource.release(ClusterBinding.java:134)
        at com.mongodb.client.internal.ClientSessionBinding$SessionBindingConnectionSource.release(ClientSessionBinding.java:152)
        at com.mongodb.internal.operation.QueryBatchCursor.releaseConnectionSourceIfNoServerCursor(QueryBatchCursor.java:357)
        at com.mongodb.internal.operation.QueryBatchCursor.getMore(QueryBatchCursor.java:287)
        at com.mongodb.internal.operation.QueryBatchCursor.hasNext(QueryBatchCursor.java:141)
        at com.mongodb.internal.operation.ChangeStreamBatchCursor$1.apply(ChangeStreamBatchCursor.java:68)
        at com.mongodb.internal.operation.ChangeStreamBatchCursor$1.apply(ChangeStreamBatchCursor.java:64)
        at com.mongodb.internal.operation.ChangeStreamBatchCursor.resumeableOperation(ChangeStreamBatchCursor.java:182)
        ... 7 more

2021-06-07 11:33:55,276 INFO  [org.apa.cam.com.mon.MongoDbChangeStreamsThread] (main) Stopped MongoDB Tailable Cursor consumer, bound to collection: db: test, col: streamChangesCollection
2021-06-07 11:33:55,278 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Stopping MongoDB Tailable Cursor consumer, bound to collection: db: test, col: persistentTailingCollection
2021-06-07 11:33:55,279 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Going to wait for stopping
2021-06-07 11:33:55,411 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (Camel (camel-1) thread #1 - mongodb://camelMongoClient) Cursor was closed, likely the consumer was stopped and closed the cursor on purpose.: java.lang.IllegalStateException: Attempted to decrement the reference count below 0
        at com.mongodb.internal.binding.AbstractReferenceCounted.release(AbstractReferenceCounted.java:39)
        at com.mongodb.internal.binding.ClusterBinding$ClusterBindingConnectionSource.release(ClusterBinding.java:134)
        at com.mongodb.client.internal.ClientSessionBinding$SessionBindingConnectionSource.release(ClientSessionBinding.java:152)
        at com.mongodb.internal.operation.QueryBatchCursor.releaseConnectionSourceIfNoServerCursor(QueryBatchCursor.java:357)
        at com.mongodb.internal.operation.QueryBatchCursor.getMore(QueryBatchCursor.java:287)
        at com.mongodb.internal.operation.QueryBatchCursor.hasNext(QueryBatchCursor.java:141)
        at com.mongodb.client.internal.MongoBatchCursorAdapter.hasNext(MongoBatchCursorAdapter.java:54)
        at org.apache.camel.component.mongodb.MongoDbTailingThread.doRun(MongoDbTailingThread.java:112)
        at org.apache.camel.component.mongodb.MongoAbstractConsumerThread.run(MongoAbstractConsumerThread.java:70)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)

2021-06-07 11:33:55,436 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Stopped MongoDB Tailable Cursor consumer, bound to collection: db: test, col: persistentTailingCollection
2021-06-07 11:33:55,437 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Stopping MongoDB Tailable Cursor consumer, bound to collection: db: test, col: tailingCollection
2021-06-07 11:33:55,437 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Going to wait for stopping
2021-06-07 11:33:56,301 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Stopped MongoDB Tailable Cursor consumer, bound to collection: db: test, col: tailingCollection
2021-06-07 11:33:56,303 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main) Routes shutdown summary (total:3 stopped:3)
2021-06-07 11:33:56,303 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Stopped route1 (mongodb://camelMongoClient)
2021-06-07 11:33:56,303 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Stopped persistentTailingCollection (mongodb://camelMongoClient)
2021-06-07 11:33:56,303 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Stopped route2 (mongodb://camelMongoClient)
2021-06-07 11:33:56,305 INFO  [org.mon.dri.connection] (main) Closed connection [connectionId{localValue:18, serverValue:22}] to localhost:49178 because the pool has been closed.
2021-06-07 11:33:56,310 INFO  [org.mon.dri.connection] (main) Closed connection [connectionId{localValue:17, serverValue:21}] to localhost:49178 because the pool has been closed.
2021-06-07 11:33:56,311 INFO  [org.mon.dri.connection] (main) Closed connection [connectionId{localValue:12, serverValue:16}] to localhost:49178 because the pool has been closed.
2021-06-07 11:33:56,311 INFO  [org.mon.dri.connection] (main) Closed connection [connectionId{localValue:16, serverValue:20}] to localhost:49178 because the pool has been closed.
2021-06-07 11:33:56,315 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main) Apache Camel 3.10.0 (camel-1) shutdown in 1s634ms (uptime:10s54ms)
2021-06-07 11:33:56,340 INFO  [io.quarkus] (main) Quarkus stopped in 1.683s
[INFO] 
[INFO] Results:
[INFO] 
[ERROR] Errors: 
[ERROR]   MongoDbTest.testPersistentTailingConsumer:171->waitForTailingResults:283 » ConditionTimeout

And this is when testPersistentTailingConsumer() is disabled and testTailingConsumer() is enabled:

[INFO] Running org.apache.camel.quarkus.component.mongodb.it.MongoDbTest
2021-06-07 11:38:44,378 INFO  [org.apa.cam.qua.com.mon.it.MongoDbTestResource] (pool-4-thread-1) TestcontainersConfiguration(userProperties={docker.client.strategy=org.testcontainers.dockerclient.EnvironmentAndSystemPropertyClientProviderStrategy}, classpathProperties={}, environment={PATH=/home/ppalaga/gems/bin:/home/ppalaga/orgs/graalvm/mx:/home/ppalaga/bin/async-profiler-1.6-linux-x64:/home/ppalaga/bin/vscode-installations/code/bin:/home/ppalaga/.yarn/bin:/home/ppalaga/.config/yarn/global/node_modules/.bin:/home/ppalaga/bin:/home/ppalaga/bin/gradle-3.5.x/bin:/home/ppalaga/gems/bin:/home/ppalaga/.sdkman/candidates/mvnd/current/bin:/home/ppalaga/.sdkman/candidates/maven/current/bin:/home/ppalaga/.sdkman/candidates/jbang/current/bin:/home/ppalaga/.sdkman/candidates/jbake/current/bin:/home/ppalaga/.sdkman/candidates/java/current/bin:/home/ppalaga/orgs/graalvm/mx:/home/ppalaga/bin/async-profiler-1.6-linux-x64:/home/ppalaga/bin/vscode-installations/code/bin:/home/ppalaga/.yarn/bin:/home/ppalaga/.config/yarn/global/node_modules/.bin:/home/ppalaga/bin:/home/ppalaga/bin/gradle-3.5.x/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin, INVOCATION_ID=91cf6a0b3e6545bba8bbfe4dd01c306b, XAUTHORITY=/run/user/1000/xauth_gXOUKd, SDKMAN_VERSION=5.11.5+713, HISTCONTROL=ignoredups, XDG_DATA_DIRS=/home/ppalaga/.local/share/flatpak/exports/share:/var/lib/flatpak/exports/share:/usr/local/share:/usr/share, DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus, ANDROID_HOME=/home/ppalaga/bin/android/android-sdk, XDG_CURRENT_DESKTOP=KDE, JOURNAL_STREAM=8:22148, QT_AUTO_SCREEN_SCALE_FACTOR=0, MAVEN_HOME=/home/ppalaga/bin/maven/apache-maven-3.6.x, MAIL=/var/spool/mail/ppalaga, SSH_AGENT_PID=3189, SDKMAN_DIR=/home/ppalaga/.sdkman, GRAALVM_HOME=/home/ppalaga/.sdkman/candidates/java/21.1.0.r11-grl, SESSION_MANAGER=local/unix:@/tmp/.ICE-unix/3268,unix/unix:/tmp/.ICE-unix/3268, LOGNAME=ppalaga, JBANG_EDITOR=code, MANAGERPID=3118, PWD=/home/ppalaga/orgs/cq/camel-quarkus/integration-tests/mongodb, XCURSOR_THEME=breeze_cursors, LANGUAGE=en_US, KDE_SESSION_VERSION=5, LESSOPEN=||/usr/bin/lesspipe.sh %s, SHELL=/bin/bash, SDKMAN_CANDIDATES_API=https://api.sdkman.io/2, ECLIPSE_WORKSPACE=/home/ppalaga/orgs/cq, OLDPWD=/home/ppalaga/orgs/cq/camel-quarkus/integration-tests/mongodb, GEM_HOME=/home/ppalaga/gems, KDE_FULL_SESSION=true, SSH_ASKPASS=/usr/bin/ksshaskpass, XDG_SESSION_PATH=/org/freedesktop/DisplayManager/Session0, FG_AIRCRAFT=/home/ppalaga/FlightGear/Aircraft, MVND_HOME=/home/ppalaga/.sdkman/candidates/mvnd/current, SYSTEMD_EXEC_PID=3412, LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=01;37;41:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.zst=01;31:*.tzst=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.wim=01;31:*.swm=01;31:*.dwm=01;31:*.esd=01;31:*.jpg=01;35:*.jpeg=01;35:*.mjpg=01;35:*.mjpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.webp=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=01;36:*.au=01;36:*.flac=01;36:*.m4a=01;36:*.mid=01;36:*.midi=01;36:*.mka=01;36:*.mp3=01;36:*.mpc=01;36:*.ogg=01;36:*.ra=01;36:*.wav=01;36:*.oga=01;36:*.opus=01;36:*.spx=01;36:*.xspf=01;36:, XDG_SESSION_DESKTOP=KDE, SHLVL=2, FG_SCENERY=/home/ppalaga/FlightGear/Scenery, KDE_APPLICATIONS_AS_SCOPE=1, OXYGEN_DISABLE_INNER_SHADOWS_HACK=1, HISTSIZE=100000, SDKMAN_OLD_PWD=/home/ppalaga/orgs/cq/camel-quarkus/integration-tests/mongodb, JAVA_HOME=/usr/lib/jvm/java-11-openjdk, BASH_FUNC_which%%=() {  ( alias;
 eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot "$@"
}, JBANG_HOME=/home/ppalaga/.sdkman/candidates/jbang/current, TERM=xterm, KDE_SESSION_UID=1000, XDG_CONFIG_DIRS=/etc/xdg:/usr/share/kde-settings/kde-profile/default/xdg, XDG_SEAT_PATH=/org/freedesktop/DisplayManager/Seat0, LANG=en_IE.UTF-8, XDG_SESSION_ID=1, MOZ_GMP_PATH=/usr/lib64/mozilla/plugins/gmp-gmpopenh264/system-installed, XDG_SESSION_TYPE=x11, HISTFILESIZE=100000, DISPLAY=:0, GTK_RC_FILES=/etc/gtk/gtkrc:/home/ppalaga/.gtkrc:/home/ppalaga/.config/gtkrc, which_declare=declare -f, ECLIPSE_HOME=/home/ppalaga/bin/eclipse-installations/java-latest/eclipse, MAVEN_CMD_LINE_ARGS= -DtrimStackTrace=false --no-snapshot-updates clean test, _=/usr/lib/jvm/java-11-openjdk-11.0.11.0.9-2.fc34.x86_64/bin/java, XDG_SESSION_CLASS=user, SDKMAN_CANDIDATES_DIR=/home/ppalaga/.sdkman/candidates, JBAKE_HOME=/home/ppalaga/.sdkman/candidates/jbake/current, XCURSOR_SIZE=24, LIBOVERLAY_SCROLLBAR=0, GDK_CORE_DEVICE_EVENTS=1, DESKTOP_SESSION=/usr/share/xsessions/plasmax11, MAVEN_PROJECTBASEDIR=/home/ppalaga/orgs/cq/camel-quarkus, SDKMAN_PLATFORM=linuxx64, USER=ppalaga, GTK2_RC_FILES=/etc/gtk-2.0/gtkrc:/home/ppalaga/.gtkrc-2.0:/home/ppalaga/.gtkrc-2.0-kde4:/home/ppalaga/.config/gtkrc-2.0, XDG_MENU_PREFIX=kf5-, XDG_SEAT=seat0, SSH_AUTH_SOCK=/tmp/ssh-XXXXXXbSzAX2/agent.3133, EDITOR=/home/ppalaga/bin/nano-ansi.sh, PK_OFFLINE_UPDATE=1, GTK_OVERLAY_SCROLLING=0, HOSTNAME=terpistone, KDEDIRS=/usr, XDG_RUNTIME_DIR=/run/user/1000, XDG_VTNR=2, HOME=/home/ppalaga})
2021-06-07 11:38:44,403 INFO  [org.tes.doc.DockerClientProviderStrategy] (pool-4-thread-1) Loaded org.testcontainers.dockerclient.EnvironmentAndSystemPropertyClientProviderStrategy from ~/.testcontainers.properties, will try it first
2021-06-07 11:38:44,799 INFO  [org.tes.doc.DockerClientProviderStrategy] (pool-4-thread-1) Found Docker environment with Environment variables, system properties and defaults. Resolved dockerHost=unix:///var/run/docker.sock
2021-06-07 11:38:44,800 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) Docker host IP address is localhost
2021-06-07 11:38:44,833 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) Connected to docker: 
  Server Version: 20.10.6
  API Version: 1.41
  Operating System: Fedora 34 (KDE Plasma)
  Total Memory: 64247 MB
2021-06-07 11:38:44,836 INFO  [org.tes.uti.ImageNameSubstitutor] (pool-4-thread-1) Image name substitution will be performed by: DefaultImageNameSubstitutor (composite of 'ConfigurationFileImageNameSubstitutor' and 'PrefixingImageNameSubstitutor')
2021-06-07 11:38:44,873 INFO  [org.tes.uti.RegistryAuthLocator] (pool-4-thread-1) Failure when attempting to lookup auth config. Please ignore if you don't have images in an authenticated registry. Details: (dockerImageName: testcontainers/ryuk:0.3.1, configFile: /home/ppalaga/.docker/config.json. Falling back to docker-java default behaviour. Exception message: /home/ppalaga/.docker/config.json (No such file or directory)
2021-06-07 11:38:45,376 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) Ryuk started - will monitor and terminate Testcontainers containers on JVM exit
2021-06-07 11:38:45,376 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) Checking the system...
2021-06-07 11:38:45,377 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) ✔︎ Docker server version should be at least 1.6.0
2021-06-07 11:38:45,462 INFO  [org.tes.DockerClientFactory] (pool-4-thread-1) ✔︎ Docker environment should have more than 2GB free disk space
2021-06-07 11:38:45,494 INFO  [🐳 .4]] (pool-4-thread-1) Creating container for image: mongo:4.4
2021-06-07 11:38:45,756 INFO  [🐳 .4]] (pool-4-thread-1) Starting container with ID: d52bed2e4d6c244d352b1359dd2db9dfd002e47cb5eca9c84feee3f95c3c6082
2021-06-07 11:38:46,148 INFO  [🐳 .4]] (pool-4-thread-1) Container mongo:4.4 is starting: d52bed2e4d6c244d352b1359dd2db9dfd002e47cb5eca9c84feee3f95c3c6082
2021-06-07 11:38:47,330 INFO  [🐳 .4]] (pool-4-thread-1) Container mongo:4.4 started in PT1.867867S
2021-06-07 11:38:48,042 INFO  [org.mon.dri.cluster] (pool-4-thread-1) Cluster created with settings {hosts=[localhost:49188], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:38:48,074 INFO  [org.mon.dri.cluster] (pool-4-thread-1) Cluster description not yet available. Waiting for 30000 ms before timing out
2021-06-07 11:38:48,092 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde928f686221e0fd92289', description='null'}-localhost:49188) Opened connection [connectionId{localValue:2, serverValue:6}] to localhost:49188
2021-06-07 11:38:48,092 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde928f686221e0fd92289', description='null'}-localhost:49188) Opened connection [connectionId{localValue:1, serverValue:5}] to localhost:49188
2021-06-07 11:38:48,099 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde928f686221e0fd92289', description='null'}-localhost:49188) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49188, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=16769828, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde92661e317f161082580, counter=6}, lastWriteDate=Mon Jun 07 11:38:47 CEST 2021, lastUpdateTimeNanos=8117303622997}
2021-06-07 11:38:48,112 INFO  [org.mon.dri.connection] (pool-4-thread-1) Opened connection [connectionId{localValue:3, serverValue:7}] to localhost:49188
2021-06-07 11:38:48,189 INFO  [org.mon.dri.connection] (pool-4-thread-1) Closed connection [connectionId{localValue:3, serverValue:7}] to localhost:49188 because the pool has been closed.
2021-06-07 11:38:48,652 INFO  [org.mon.dri.cluster] (main) Cluster created with settings {hosts=[localhost:49188], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:38:48,656 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde928f686221e0fd9228a', description='null'}-localhost:49188) Opened connection [connectionId{localValue:4, serverValue:8}] to localhost:49188
2021-06-07 11:38:48,657 INFO  [org.mon.dri.cluster] (main) Cluster created with settings {hosts=[localhost:49188], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:38:48,657 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde928f686221e0fd9228a', description='null'}-localhost:49188) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49188, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=2274855, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde92661e317f161082580, counter=6}, lastWriteDate=Mon Jun 07 11:38:48 CEST 2021, lastUpdateTimeNanos=8117867782695}
2021-06-07 11:38:48,656 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde928f686221e0fd9228a', description='null'}-localhost:49188) Opened connection [connectionId{localValue:5, serverValue:9}] to localhost:49188
2021-06-07 11:38:48,670 INFO  [org.mon.dri.cluster] (main) Cluster created with settings {hosts=[localhost:49188], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:38:48,671 INFO  [org.mon.dri.cluster] (main) Cluster created with settings {hosts=[localhost:49188], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:38:48,675 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde928f686221e0fd9228c', description='null'}-localhost:49188) Opened connection [connectionId{localValue:8, serverValue:12}] to localhost:49188
2021-06-07 11:38:48,676 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde928f686221e0fd9228c', description='null'}-localhost:49188) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49188, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=3466491, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde92661e317f161082580, counter=6}, lastWriteDate=Mon Jun 07 11:38:48 CEST 2021, lastUpdateTimeNanos=8117886968986}
2021-06-07 11:38:48,677 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde928f686221e0fd9228c', description='null'}-localhost:49188) Opened connection [connectionId{localValue:9, serverValue:14}] to localhost:49188
2021-06-07 11:38:48,678 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde928f686221e0fd9228d', description='null'}-localhost:49188) Opened connection [connectionId{localValue:11, serverValue:15}] to localhost:49188
2021-06-07 11:38:48,680 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde928f686221e0fd9228b', description='null'}-localhost:49188) Opened connection [connectionId{localValue:6, serverValue:11}] to localhost:49188
2021-06-07 11:38:48,680 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde928f686221e0fd9228d', description='null'}-localhost:49188) Opened connection [connectionId{localValue:10, serverValue:13}] to localhost:49188
2021-06-07 11:38:48,680 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde928f686221e0fd9228b', description='null'}-localhost:49188) Opened connection [connectionId{localValue:7, serverValue:10}] to localhost:49188
2021-06-07 11:38:48,682 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde928f686221e0fd9228b', description='null'}-localhost:49188) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49188, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=7169438, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde92661e317f161082580, counter=6}, lastWriteDate=Mon Jun 07 11:38:48 CEST 2021, lastUpdateTimeNanos=8117892285748}
2021-06-07 11:38:48,682 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde928f686221e0fd9228d', description='null'}-localhost:49188) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49188, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=6992313, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde92661e317f161082580, counter=6}, lastWriteDate=Mon Jun 07 11:38:48 CEST 2021, lastUpdateTimeNanos=8117892116197}
2021-06-07 11:38:48,743 INFO  [org.apa.cam.qua.cor.CamelBootstrapRecorder] (main) Bootstrap runtime: org.apache.camel.quarkus.main.CamelMainRuntime
2021-06-07 11:38:48,832 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (main) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=tailingCollection&database=test&tailTrackIncreasingField=increasing
2021-06-07 11:38:48,837 INFO  [org.mon.dri.connection] (main) Opened connection [connectionId{localValue:12, serverValue:16}] to localhost:49188
2021-06-07 11:38:48,862 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (main) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=persistentTailingCollection&database=test&persistentId=darwin&persistentTailTracking=true&tailTrackIncreasingField=increasing
2021-06-07 11:38:48,864 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (main) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=streamChangesCollection&consumerType=changeStreams&database=test
2021-06-07 11:38:48,877 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Starting MongoDB Tailable Cursor consumer, binding to collection: db: com.mongodb.client.internal.MongoDatabaseImpl@40ed1d35, col: tailingCollection
2021-06-07 11:38:48,948 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Starting MongoDB Tailable Cursor consumer, binding to collection: db: com.mongodb.client.internal.MongoDatabaseImpl@45e3ed62, col: persistentTailingCollection
2021-06-07 11:38:48,994 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main) Routes startup summary (total:3 started:3)
2021-06-07 11:38:48,995 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Started route1 (mongodb://camelMongoClient)
2021-06-07 11:38:48,995 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Started persistentTailingCollection (mongodb://camelMongoClient)
2021-06-07 11:38:48,995 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Started route2 (mongodb://camelMongoClient)
2021-06-07 11:38:48,995 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main) Apache Camel 3.10.0 (camel-1) started in 197ms (build:0ms init:69ms start:128ms)
2021-06-07 11:38:49,092 INFO  [io.quarkus] (main) Quarkus 2.0.0.CR3 on JVM started in 6.076s. Listening on: http://localhost:33723
2021-06-07 11:38:49,093 INFO  [io.quarkus] (main) Profile test activated. 
2021-06-07 11:38:49,093 INFO  [io.quarkus] (main) Installed features: [camel-core, camel-mongodb, camel-mongodb-gridfs, camel-support-common, camel-support-mongodb, cdi, mongodb-client, resteasy, resteasy-jsonb, smallrye-context-propagation]
2021-06-07 11:38:49,103 INFO  [org.mon.dri.cluster] (main) Cluster created with settings {hosts=[localhost:49188], mode=SINGLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms'}
2021-06-07 11:38:49,117 INFO  [org.mon.dri.connection] (cluster-ClusterId{value='60bde929f686221e0fd9228f', description='null'}-localhost:49188) Opened connection [connectionId{localValue:13, serverValue:17}] to localhost:49188
2021-06-07 11:38:49,117 INFO  [org.mon.dri.connection] (cluster-rtt-ClusterId{value='60bde929f686221e0fd9228f', description='null'}-localhost:49188) Opened connection [connectionId{localValue:14, serverValue:18}] to localhost:49188
2021-06-07 11:38:49,117 INFO  [org.mon.dri.cluster] (cluster-ClusterId{value='60bde929f686221e0fd9228f', description='null'}-localhost:49188) Monitor thread successfully connected to server with description ServerDescription{address=localhost:49188, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, minWireVersion=0, maxWireVersion=9, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=12084721, setName='my-mongo-set', canonicalAddress=mongodb_private:27017, hosts=[mongodb_private:27017], passives=[], arbiters=[], primary='mongodb_private:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000001, setVersion=1, topologyVersion=TopologyVersion{processId=60bde92661e317f161082580, counter=6}, lastWriteDate=Mon Jun 07 11:38:48 CEST 2021, lastUpdateTimeNanos=8118328444128}
2021-06-07 11:38:49,445 INFO  [org.mon.dri.connection] (main) Opened connection [connectionId{localValue:15, serverValue:19}] to localhost:49188
2021-06-07 11:38:49,901 INFO  [org.mon.dri.connection] (Camel (camel-1) thread #0 - mongodb://camelMongoClient) Opened connection [connectionId{localValue:16, serverValue:20}] to localhost:49188
2021-06-07 11:38:50,023 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=outputTypeDocumentList&database=test&dynamicity=true&operation=findAll&outputType=DocumentList
2021-06-07 11:38:52,963 INFO  [org.mon.dri.connection] (Camel (camel-1) thread #1 - mongodb://camelMongoClient) Opened connection [connectionId{localValue:17, serverValue:21}] to localhost:49188
2021-06-07 11:38:56,653 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=outputTypeDocument&database=test&dynamicity=true&operation=findOneByQuery&outputType=Document
2021-06-07 11:38:56,813 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=camelMongoClientCamelTest&database=test&dynamicity=true&operation=insert
2021-06-07 11:38:56,848 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=camelMongoClientCamelTest&database=test&dynamicity=true&operation=findAll&outputType=MongoIterable
2021-06-07 11:38:56,887 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://myMongoClient?collection=myMongoClientCamelTest&database=test&dynamicity=true&operation=insert
2021-06-07 11:38:56,890 INFO  [org.mon.dri.connection] (executor-thread-0) Opened connection [connectionId{localValue:18, serverValue:22}] to localhost:49188
2021-06-07 11:38:56,922 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://myMongoClient?collection=myMongoClientCamelTest&database=test&dynamicity=true&operation=findAll&outputType=MongoIterable
2021-06-07 11:38:56,939 INFO  [org.apa.cam.com.mon.MongoDbEndpoint] (executor-thread-0) Initialising MongoDb endpoint: mongodb://camelMongoClient?collection=dynamicCamelTest&database=test&dynamicity=true&operation=insert
2021-06-07 11:38:56,994 INFO  [org.mon.dri.connection] (main) Closed connection [connectionId{localValue:15, serverValue:19}] to localhost:49188 because the pool has been closed.
[ERROR] Tests run: 10, Failures: 0, Errors: 1, Skipped: 1, Time elapsed: 16.354 s <<< FAILURE! - in org.apache.camel.quarkus.component.mongodb.it.MongoDbTest
[ERROR] testTailingConsumer  Time elapsed: 5.572 s  <<< ERROR!
org.awaitility.core.ConditionTimeoutException: Lambda expression in org.apache.camel.quarkus.component.mongodb.it.MongoDbTest that uses java.lang.String: expected the predicate to return <true> but it returned <false> for input of <{size=0}> within 5 seconds.
        at org.awaitility.core.ConditionAwaiter.await(ConditionAwaiter.java:166)
        at org.awaitility.core.AbstractHamcrestCondition.await(AbstractHamcrestCondition.java:86)
        at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:939)
        at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:645)
        at org.awaitility.core.ConditionFactory.until(ConditionFactory.java:662)
        at org.apache.camel.quarkus.component.mongodb.it.MongoDbTest.waitForTailingResults(MongoDbTest.java:283)
        at org.apache.camel.quarkus.component.mongodb.it.MongoDbTest.testTailingConsumer(MongoDbTest.java:156)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.quarkus.test.junit.QuarkusTestExtension.runExtensionMethod(QuarkusTestExtension.java:993)
        at io.quarkus.test.junit.QuarkusTestExtension.interceptTestMethod(QuarkusTestExtension.java:870)
        at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
        at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
        at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:149)
        at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:140)
        at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:84)
        at org.junit.jupiter.engine.execution.ExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(ExecutableInvoker.java:115)
        at org.junit.jupiter.engine.execution.ExecutableInvoker.lambda$invoke$0(ExecutableInvoker.java:105)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)
        at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)
        at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:104)
        at org.junit.jupiter.engine.execution.ExecutableInvoker.invoke(ExecutableInvoker.java:98)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$6(TestMethodTestDescriptor.java:210)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:206)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:131)
        at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:65)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:139)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
        at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
        at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
        at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
        at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
        at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
        at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:38)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$5(NodeTestTask.java:143)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$7(NodeTestTask.java:129)
        at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:127)
        at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:126)
        at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:84)
        at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:32)
        at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
        at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:51)
        at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:108)
        at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:88)
        at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:54)
        at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:67)
        at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:52)
        at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:96)
        at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:75)
        at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invokeAllTests(JUnitPlatformProvider.java:150)
        at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invoke(JUnitPlatformProvider.java:124)
        at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
        at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
        at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
        at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)

[INFO] Running org.apache.camel.quarkus.component.mongodb.it.MongodbGridfsTest
2021-06-07 11:38:57,012 INFO  [org.apa.cam.com.mon.gri.GridFsEndpoint] (executor-thread-0) Initialize GridFS endpoint: mongodb-gridfs://camelMongoClient?database=test&operation=create
2021-06-07 11:38:57,127 INFO  [org.apa.cam.com.mon.gri.GridFsEndpoint] (executor-thread-0) Initialize GridFS endpoint: mongodb-gridfs://camelMongoClient?database=test&operation=findOne
2021-06-07 11:38:57,203 INFO  [org.apa.cam.com.mon.gri.GridFsEndpoint] (executor-thread-0) Initialize GridFS endpoint: mongodb-gridfs://camelMongoClient?database=test&operation=remove
2021-06-07 11:38:57,242 INFO  [org.apa.cam.com.mon.gri.GridFsEndpoint] (executor-thread-0) Initialize GridFS endpoint: mongodb-gridfs://myMongoClient?database=test&operation=create
2021-06-07 11:38:57,259 INFO  [org.apa.cam.com.mon.gri.GridFsEndpoint] (executor-thread-0) Initialize GridFS endpoint: mongodb-gridfs://myMongoClient?database=test&operation=findOne
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.233 s - in org.apache.camel.quarkus.component.mongodb.it.MongodbGridfsTest
2021-06-07 11:38:57,308 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main) Apache Camel 3.10.0 (camel-1) shutting down
2021-06-07 11:38:57,311 INFO  [org.apa.cam.com.mon.MongoDbChangeStreamsThread] (main) Stopping MongoDB Tailable Cursor consumer, bound to collection: db: test, col: streamChangesCollection
2021-06-07 11:38:57,312 INFO  [org.apa.cam.com.mon.MongoDbChangeStreamsThread] (main) Going to wait for stopping
2021-06-07 11:38:57,780 WARN  [org.apa.cam.com.mon.MongoDbChangeStreamsThread] (Camel (camel-1) thread #2 - mongodb://camelMongoClient) Exception from consuming from MongoDB caused by Attempted to decrement the reference count below 0. ConsumerThread will be stopped.: com.mongodb.MongoException: Attempted to decrement the reference count below 0
        at com.mongodb.MongoException.fromThrowableNonNull(MongoException.java:83)
        at com.mongodb.internal.operation.ChangeStreamBatchCursor.resumeableOperation(ChangeStreamBatchCursor.java:185)
        at com.mongodb.internal.operation.ChangeStreamBatchCursor.hasNext(ChangeStreamBatchCursor.java:64)
        at com.mongodb.client.internal.MongoChangeStreamCursorImpl.hasNext(MongoChangeStreamCursorImpl.java:58)
        at org.apache.camel.component.mongodb.MongoDbChangeStreamsThread.doRun(MongoDbChangeStreamsThread.java:72)
        at org.apache.camel.component.mongodb.MongoAbstractConsumerThread.run(MongoAbstractConsumerThread.java:70)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.IllegalStateException: Attempted to decrement the reference count below 0
        at com.mongodb.internal.binding.AbstractReferenceCounted.release(AbstractReferenceCounted.java:39)
        at com.mongodb.internal.binding.ClusterBinding$ClusterBindingConnectionSource.release(ClusterBinding.java:134)
        at com.mongodb.client.internal.ClientSessionBinding$SessionBindingConnectionSource.release(ClientSessionBinding.java:152)
        at com.mongodb.internal.operation.QueryBatchCursor.releaseConnectionSourceIfNoServerCursor(QueryBatchCursor.java:357)
        at com.mongodb.internal.operation.QueryBatchCursor.getMore(QueryBatchCursor.java:287)
        at com.mongodb.internal.operation.QueryBatchCursor.hasNext(QueryBatchCursor.java:141)
        at com.mongodb.internal.operation.ChangeStreamBatchCursor$1.apply(ChangeStreamBatchCursor.java:68)
        at com.mongodb.internal.operation.ChangeStreamBatchCursor$1.apply(ChangeStreamBatchCursor.java:64)
        at com.mongodb.internal.operation.ChangeStreamBatchCursor.resumeableOperation(ChangeStreamBatchCursor.java:182)
        ... 7 more

2021-06-07 11:38:57,782 INFO  [org.apa.cam.com.mon.MongoDbChangeStreamsThread] (main) Stopped MongoDB Tailable Cursor consumer, bound to collection: db: test, col: streamChangesCollection
2021-06-07 11:38:57,784 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Stopping MongoDB Tailable Cursor consumer, bound to collection: db: test, col: persistentTailingCollection
2021-06-07 11:38:57,784 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Going to wait for stopping
2021-06-07 11:38:57,968 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Stopped MongoDB Tailable Cursor consumer, bound to collection: db: test, col: persistentTailingCollection
2021-06-07 11:38:57,969 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Stopping MongoDB Tailable Cursor consumer, bound to collection: db: test, col: tailingCollection
2021-06-07 11:38:57,970 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Going to wait for stopping
2021-06-07 11:38:58,967 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (Camel (camel-1) thread #0 - mongodb://camelMongoClient) Cursor was closed, likely the consumer was stopped and closed the cursor on purpose.: java.lang.IllegalStateException: Attempted to decrement the reference count below 0
        at com.mongodb.internal.binding.AbstractReferenceCounted.release(AbstractReferenceCounted.java:39)
        at com.mongodb.internal.binding.ClusterBinding$ClusterBindingConnectionSource.release(ClusterBinding.java:134)
        at com.mongodb.client.internal.ClientSessionBinding$SessionBindingConnectionSource.release(ClientSessionBinding.java:152)
        at com.mongodb.internal.operation.QueryBatchCursor.releaseConnectionSourceIfNoServerCursor(QueryBatchCursor.java:357)
        at com.mongodb.internal.operation.QueryBatchCursor.getMore(QueryBatchCursor.java:287)
        at com.mongodb.internal.operation.QueryBatchCursor.hasNext(QueryBatchCursor.java:141)
        at com.mongodb.client.internal.MongoBatchCursorAdapter.hasNext(MongoBatchCursorAdapter.java:54)
        at org.apache.camel.component.mongodb.MongoDbTailingThread.doRun(MongoDbTailingThread.java:112)
        at org.apache.camel.component.mongodb.MongoAbstractConsumerThread.run(MongoAbstractConsumerThread.java:70)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:829)

2021-06-07 11:38:58,968 INFO  [org.apa.cam.com.mon.MongoDbTailingThread] (main) Stopped MongoDB Tailable Cursor consumer, bound to collection: db: test, col: tailingCollection
2021-06-07 11:38:58,969 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main) Routes shutdown summary (total:3 stopped:3)
2021-06-07 11:38:58,970 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Stopped route1 (mongodb://camelMongoClient)
2021-06-07 11:38:58,970 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Stopped persistentTailingCollection (mongodb://camelMongoClient)
2021-06-07 11:38:58,970 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main)     Stopped route2 (mongodb://camelMongoClient)
2021-06-07 11:38:58,972 INFO  [org.mon.dri.connection] (main) Closed connection [connectionId{localValue:18, serverValue:22}] to localhost:49188 because the pool has been closed.
2021-06-07 11:38:58,975 INFO  [org.mon.dri.connection] (main) Closed connection [connectionId{localValue:17, serverValue:21}] to localhost:49188 because the pool has been closed.
2021-06-07 11:38:58,975 INFO  [org.mon.dri.connection] (main) Closed connection [connectionId{localValue:12, serverValue:16}] to localhost:49188 because the pool has been closed.
2021-06-07 11:38:58,976 INFO  [org.mon.dri.connection] (main) Closed connection [connectionId{localValue:16, serverValue:20}] to localhost:49188 because the pool has been closed.
2021-06-07 11:38:58,979 INFO  [org.apa.cam.imp.eng.AbstractCamelContext] (main) Apache Camel 3.10.0 (camel-1) shutdown in 1s671ms (uptime:10s112ms)
2021-06-07 11:38:59,001 INFO  [io.quarkus] (main) Quarkus stopped in 1.716s
[INFO] 
[INFO] Results:
[INFO] 
[ERROR] Errors: 
[ERROR]   MongoDbTest.testTailingConsumer:156->waitForTailingResults:283 » ConditionTimeout

@ppalaga ppalaga changed the title Intermittent failures in MongoDbTest.testTailingConsumer() Intermittent failures in MongoDbTest.testTailingConsumer() and MongoDbTest.testPersistentTailingConsumer() Jun 7, 2021
ppalaga added a commit to ppalaga/camel-quarkus that referenced this issue Jun 7, 2021
@ppalaga
Temporarily disable MongoDbTest.testTailingConsumer() and MongoDbTest…
2750baf 
….testPersistentTailingConsumer() apache#2658
ppalaga added a commit that referenced this issue Jun 7, 2021
@ppalaga
Fixup 8ce5068 Intermittent failures in MongoDbTest.testTailingConsume…
4a7527e 
…r() #2658
ppalaga added a commit that referenced this issue Jun 7, 2021
@ppalaga
Temporarily disable MongoDbTest.testTailingConsumer() and MongoDbTest…
d43ba4a 
….testPersistentTailingConsumer() #2658
@ppalaga ppalaga modified the milestones: 2.0.0, 2.0.0-M2 Jun 7, 2021
JiriOndrusek added a commit to JiriOndrusek/camel-quarkus that referenced this issue Jun 8, 2021
@JiriOndrusek
Intermittent failures in MongoDbTest.testTailingConsumer() and MongoD…
32f4f03 
…bTest.testPersistentTailingConsumer() apache#2658
@JiriOndrusek JiriOndrusek mentioned this issue Jun 8, 2021
Merged
JiriOndrusek added a commit to JiriOndrusek/camel-quarkus that referenced this issue Jun 8, 2021
@JiriOndrusek
Intermittent failures in MongoDbTest.testTailingConsumer() and MongoD…
ea64347 
…bTest.testPersistentTailingConsumer() apache#2658
ppalaga pushed a commit that referenced this issue Jun 8, 2021
@JiriOndrusek @ppalaga
Intermittent failures in MongoDbTest.testTailingConsumer() and MongoD…
9e5b715 
…bTest.testPersistentTailingConsumer() #2658
ppalaga added a commit to ppalaga/camel-quarkus that referenced this issue Jun 16, 2021
@ppalaga
Fixup apache#2658 Intermittent failures in MongoDbTest.testTailingCon…
d78ea10 
…sumer() and MongoDbTest.testPersistentTailingConsumer()
ppalaga added a commit that referenced this issue Jun 16, 2021
@ppalaga
Fixup #2658 Intermittent failures in MongoDbTest.testTailingConsumer(…
e4d2f9d 
…) and MongoDbTest.testPersistentTailingConsumer()
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@JiriOndrusek JiriOndrusek

Labels
None yet
Projects
None yet
Milestone
2.0.0-M2
2 participants
@ppalaga @JiriOndrusek