`VncRecordingContainer.reencodeRecording` hangs

[blindpirate]

Thanks for the awesome project. It really really help out. I've been experiencing this issue for several months. It happens frequently (several times per day) but I didn't find a stable way to reproduce, thus I can't provide a minimal reproducer. My project runs browser tests with Kotlin 1.6.10, Gradle 7.3. It hangs frequently if I enabled recording, regardless of format (flv/mp4). Once I disable recording, no issues at all.

Environment:

macOS 11.3.1
docker desktop 4.2.0 (70708)
testcontainers 1.16.3

When it hangs, the docker ps outputs:

$ docker ps
CONTAINER ID   IMAGE                                       COMMAND                   CREATED       STATUS       PORTS                                              NAMES
8bb3dc872278   testcontainers/vnc-recorder:1.2.0           "/bin/sh -c 'echo 'c…"    3 hours ago   Up 3 hours                                                      hungry_poincare
eff7f640ef47   selenium/standalone-chrome-debug:3.141.59   "/opt/bin/entry_poin…"    3 hours ago   Up 3 hours   0.0.0.0:64092->4444/tcp, 0.0.0.0:64093->5900/tcp   blissful_lichterman
dd764547abf5   testcontainers/vnc-recorder:1.2.0           "/bin/sh -c 'echo 'c…"    3 hours ago   Up 3 hours                                                      modest_chatterjee
b56b6c98537b   selenium/standalone-chrome-debug:3.141.59   "/opt/bin/entry_poin…"    3 hours ago   Up 3 hours   0.0.0.0:64074->4444/tcp, 0.0.0.0:64075->5900/tcp   admiring_tharp
b23acaf9723c   testcontainers/vnc-recorder:1.2.0           "/bin/sh -c 'echo 'c…"    3 hours ago   Up 3 hours                                                      cranky_jang
1692aee2351f   selenium/standalone-chrome-debug:3.141.59   "/opt/bin/entry_poin…"    3 hours ago   Up 3 hours   0.0.0.0:64054->4444/tcp, 0.0.0.0:64055->5900/tcp   heuristic_meninsky
2b2e94963b45   amazon/dynamodb-local:latest                "java -jar DynamoDBL…"    3 hours ago   Up 3 hours   0.0.0.0:64042->8000/tcp                            competent_mestorf
5e61134895bb   testcontainers/sshd:1.0.0                   "sh -c 'echo \"root:$…"   3 hours ago   Up 3 hours   0.0.0.0:63665->22/tcp                              brave_mcclintock
573d1e348e81   testcontainers/ryuk:0.3.3                   "/app"                    3 hours ago   Up 3 hours   0.0.0.0:63656->8080/tcp                            testcontainers-ryuk-cda1010c-3a9a-4725-8db4-3f4b0c00f96d

The stacktrace and jstack dump:

"Test worker" #21 prio=5 os_prio=31 cpu=9934.43ms elapsed=9287.41s tid=0x00007f98db016800 nid=0x6403 waiting on condition  [0x0000700004e9e000]
   java.lang.Thread.State: WAITING (parking)
	at jdk.internal.misc.Unsafe.park(java.base@11.0.11/Native Method)
	- parking to wait for  <0x00000007fc6b1fd0> (a java.util.concurrent.CountDownLatch$Sync)
	at java.util.concurrent.locks.LockSupport.park(java.base@11.0.11/LockSupport.java:194)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.11/AbstractQueuedSynchronizer.java:885)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(java.base@11.0.11/AbstractQueuedSynchronizer.java:1039)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(java.base@11.0.11/AbstractQueuedSynchronizer.java:1345)
	at java.util.concurrent.CountDownLatch.await(java.base@11.0.11/CountDownLatch.java:232)
	at com.github.dockerjava.api.async.ResultCallbackTemplate.awaitCompletion(ResultCallbackTemplate.java:91)
	at org.testcontainers.containers.ExecInContainerPattern.execInContainer(ExecInContainerPattern.java:80)
	at org.testcontainers.containers.ContainerState.execInContainer(ContainerState.java:235)
	at org.testcontainers.containers.ContainerState.execInContainer(ContainerState.java:226)
	at org.testcontainers.containers.VncRecordingContainer$VncRecordingFormat$2.reencodeRecording(VncRecordingContainer.java:135)
	at org.testcontainers.containers.VncRecordingContainer.streamRecording(VncRecordingContainer.java:105)
	at org.testcontainers.containers.VncRecordingContainer.saveRecordingToFile(VncRecordingContainer.java:116)
	at org.testcontainers.containers.BrowserWebDriverContainer.retainRecordingIfNeeded(BrowserWebDriverContainer.java:345)
	at org.testcontainers.containers.BrowserWebDriverContainer.afterTest(BrowserWebDriverContainer.java:303)
	at com.bytelegend.app.testfixtures.JUnit5VncRecorder.afterTestExecution(JUnit5VncRecorder.kt:61)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeAfterTestExecutionCallbacks$9(TestMethodTestDescriptor.java:233)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor$$Lambda$3359/0x0000000800c8ac40.invoke(Unknown Source)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeAllAfterMethodsOrCallbacks$13(TestMethodTestDescriptor.java:273)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor$$Lambda$3361/0x0000000800c8fc40.execute(Unknown Source)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeAllAfterMethodsOrCallbacks$14(TestMethodTestDescriptor.java:273)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor$$Lambda$3360/0x0000000800c8f840.accept(Unknown Source)
	at java.util.ArrayList.forEach(java.base@11.0.11/ArrayList.java:1541)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeAllAfterMethodsOrCallbacks(TestMethodTestDescriptor.java:272)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeAfterTestExecutionCallbacks(TestMethodTestDescriptor.java:232)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:137)
	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:66)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$248/0x00000008001e3440.execute(Unknown Source)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$247/0x00000008001e3040.invoke(Unknown Source)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$246/0x00000008001e2c40.execute(Unknown Source)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService$$Lambda$252/0x00000008001e4440.accept(Unknown Source)
	at java.util.ArrayList.forEach(java.base@11.0.11/ArrayList.java:1541)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$248/0x00000008001e3440.execute(Unknown Source)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$247/0x00000008001e3040.invoke(Unknown Source)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$246/0x00000008001e2c40.execute(Unknown Source)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService$$Lambda$252/0x00000008001e4440.accept(Unknown Source)
	at java.util.ArrayList.forEach(java.base@11.0.11/ArrayList.java:1541)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$248/0x00000008001e3440.execute(Unknown Source)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$247/0x00000008001e3040.invoke(Unknown Source)
	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask$$Lambda$246/0x00000008001e2c40.execute(Unknown Source)
	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:35)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
	at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:54)
	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$$Lambda$208/0x00000008001c8040.accept(Unknown Source)
	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.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.processAllTestClasses(JUnitPlatformTestClassProcessor.java:99)
	at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor$CollectAllTestClassesExecutor.access$000(JUnitPlatformTestClassProcessor.java:79)
	at org.gradle.api.internal.tasks.testing.junitplatform.JUnitPlatformTestClassProcessor.stop(JUnitPlatformTestClassProcessor.java:75)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.stop(SuiteTestClassProcessor.java:61)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.11/Native Method)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.11/NativeMethodAccessorImpl.java:62)
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.11/DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(java.base@11.0.11/Method.java:566)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:33)
	at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94)
	at com.sun.proxy.$Proxy2.stop(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.stop(TestWorker.java:135)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.11/Native Method)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.11/NativeMethodAccessorImpl.java:62)
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.11/DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(java.base@11.0.11/Method.java:566)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:182)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:164)
	at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:414)
	at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:64)
	at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:48)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.11/ThreadPoolExecutor.java:1128)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.11/ThreadPoolExecutor.java:628)
	at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:56)
	at java.lang.Thread.run(java.base@11.0.11/Thread.java:829)

Any help/guidance on how to mitigate would be appreciated.

[kiview]

Hi @blindpirate, thanks for raising this issue. Can you correlate this in any way with the length of the video?

Can you also reproduce sometimes it when just running a single test?

[blindpirate]

Thanks @kiview for reply, I was on vacation in the past days. Now I seem to be able to narrow down the problematic test to a single test case, and it seems to be reproducible on my mac machine - running that single test hangs. It's not reproducible on my Linux servers, though.

$ ./gradlew server:app:browserTest --tests AnonymousPlayerKickOffBrowserTest

> Configure project :
Use buildTimestamp 20220209205703

> Task :utils:buildProductionGameResources
Game resources has been generated in /Users/zhb/Projects/ByteLegend/utils/build/game-resources-production
<============-> 99% EXECUTING [12m 30s]
> :server:app:browserTest > 0 tests completed
> :server:app:browserTest > Executing test com...browsertest.AnonymousPlayerKickOffBrowserTest

Unfortunately it's a private project so I can't share it publicly.

Can you correlate this in any way with the length of the video?

The recorded video is pretty small (<1M).

[kiview]

Can you confirm that the test runs fine if you disable video recording? Are you on an ARM MacBook?
We are using this image for doing the encoding.

[deejgregor]

@blindpirate are you on an ARM system, by chance (you said you are using a MacBook, are you on an M1 MacBook; what does arch show)? Or, have you possibly configured a large screen size for the browser in BrowserWebDriverContainer? If so, you might be running into this issue: #6229

[blindpirate]

No I'm on Intel mac.

[deejgregor]

@blindpirate if you have time to check, I'm curious if #6307 fixes your issue.

[regulskimichal]

Can someone else confirm if it is fixed in the newest version?

[AB-xdev]

Had the same problem as described here.
More details and our fix here.

Long time fix proposed via #8575