macOs - `sbt test` does not succeed locally

[LukaszKontowski]

sbt test does not finish successfully locally. It takes a lot of time and there are a lot of errors like in the logs below (after such errors tests continue). This happens on the macOs with M1 Pro chip using OpenJDK 11.0.16.

Cloning:https://github.com/VirtusLab/git-machete.git
remote: Counting objects 100% (126/126)
remote: Compressing objects 100% (79/79)
Receiving objects 99% (4211/4212)
Resolving deltas 99% (2625/2626)
Checking out files 99% (204/205)
Installing IntelliJ(2021.2.1, 212.5080.55)
Installed Plugin(ideprobe_2.13-0.41.0)
Installing IntelliJ(2021.2.1, 212.5080.55)
Installed Plugin(ideprobe_2.13-0.41.0)
Starting process /var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/instances/intellij-instance-212.5080.55--vdO0-R3aRBKxOxMZzFvI0Q/Contents/bin/idea in /private/var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/workspaces/ideprobe-workspace-d2eiVUiRQ9-WXN7vG7xLfA/ws
[intellij-stderr] /var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/instances/intellij-instance-212.5080.55--vdO0-R3aRBKxOxMZzFvI0Q/Contents/bin/idea: line 2:  4614 Killed: 9               /var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/instances/intellij-instance-212.5080.55--vdO0-R3aRBKxOxMZzFvI0Q/Contents/MacOS/idea "$@"
Installing IntelliJ(2021.2.1, 212.5080.55)
Installed Plugin(ideprobe_2.13-0.41.0)
Starting process /var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/instances/intellij-instance-212.5080.55--LKMmyvcDSK-fOynN93BSAQ/Contents/bin/idea in /private/var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/workspaces/ideprobe-workspace-5XZsG6lJRSClly5Kc9vrtA/ws
[intellij-stderr] /var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/instances/intellij-instance-212.5080.55--LKMmyvcDSK-fOynN93BSAQ/Contents/bin/idea: line 2:  4682 Killed: 9               /var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/instances/intellij-instance-212.5080.55--LKMmyvcDSK-fOynN93BSAQ/Contents/MacOS/idea "$@"
Installing IntelliJ(2021.2.1, 212.5080.55)
Installed Plugin(ideprobe_2.13-0.41.0)
Starting process /var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/instances/intellij-instance-212.5080.55--d1mSo8Q1QcyynRRRFsqpkQ/Contents/bin/idea in /private/var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/workspaces/ideprobe-workspace-IXudDzKKRqm6KCxevtT00w/ws
[intellij-stderr] /var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/instances/intellij-instance-212.5080.55--d1mSo8Q1QcyynRRRFsqpkQ/Contents/bin/idea: line 2:  4750 Killed: 9               /var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/instances/intellij-instance-212.5080.55--d1mSo8Q1QcyynRRRFsqpkQ/Contents/MacOS/idea "$@"

[error] Test org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.removesDirectoriesEvenAfterFailureToRunIntelliJ failed: java.lang.AssertionError: Expected instances directory cleanup, but /var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/instances/intellij-instance-212.5080.55--vdO0-R3aRBKxOxMZzFvI0Q were not removed, took 38.15 sec
[error]     at org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.removesDirectoriesEvenAfterFailureToRunIntelliJ(SingleRunFixtureTest.scala:82)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[error]     at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[error]     at java.lang.reflect.Method.invoke(Method.java:566)
[error]     ...
[error] Test org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.removesDirectoriesAfterRunTest failed: java.net.SocketTimeoutException: Accept timed out, took 38.087 sec
[error]     at java.net.PlainSocketImpl.socketAccept(Native Method)
[error]     at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:474)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:565)
[error]     at java.net.ServerSocket.accept(ServerSocket.java:533)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.$anonfun$startIn$1(InstalledIntelliJ.scala:57)
[error]     at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:62)
[error]     at scala.concurrent.package$.blocking(package.scala:124)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.startIn(InstalledIntelliJ.scala:57)
[error]     at org.virtuslab.ideprobe.IntelliJFixture.startIntelliJ(IntelliJFixture.scala:102)
[error]     at org.virtuslab.ideprobe.SingleRunIntelliJ.apply(DSL.scala:44)
[error]     at org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.removesDirectoriesAfterRunTest(SingleRunFixtureTest.scala:46)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[error]     at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[error]     at java.lang.reflect.Method.invoke(Method.java:566)
[error]     ...
[error] Test org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.shutdownsLauncherAfterTest failed: java.net.SocketTimeoutException: Accept timed out, took 38.266 sec
[error]     at java.net.PlainSocketImpl.socketAccept(Native Method)
[error]     at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:474)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:565)
[error]     at java.net.ServerSocket.accept(ServerSocket.java:533)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.$anonfun$startIn$1(InstalledIntelliJ.scala:57)
[error]     at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:62)
[error]     at scala.concurrent.package$.blocking(package.scala:124)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.startIn(InstalledIntelliJ.scala:57)
[error]     at org.virtuslab.ideprobe.IntelliJFixture.startIntelliJ(IntelliJFixture.scala:102)
[error]     at org.virtuslab.ideprobe.SingleRunIntelliJ.apply(DSL.scala:44)
[error]     at org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.shutdownsLauncherAfterTest(SingleRunFixtureTest.scala:34)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[error]     at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[error]     at java.lang.reflect.Method.invoke(Method.java:566)
[error]     ...

Installing IntelliJ(2021.2.1, 212.5080.55)

[LukaszKontowski]

Another example from failed tests:

[error] Test org.virtuslab.ideprobe.ProbeDriverJavaTest.openProject failed: java.net.SocketTimeoutException: Accept timed out, took 38.317 sec
[error]     at java.net.PlainSocketImpl.socketAccept(Native Method)
[error]     at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:474)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:565)
[error]     at java.net.ServerSocket.accept(ServerSocket.java:533)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.$anonfun$startIn$1(InstalledIntelliJ.scala:57)
[error]     at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:57)
[error]     at scala.concurrent.package$.blocking(package.scala:146)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.startIn(InstalledIntelliJ.scala:57)
[error]     at org.virtuslab.ideprobe.IntelliJFixture.startIntelliJ(IntelliJFixture.scala:102)
[error]     at org.virtuslab.ideprobe.SingleRunIntelliJ.apply(DSL.scala:44)
[error]     at org.virtuslab.ideprobe.ProbeDriverJavaTest.openProject(ProbeDriverJavaTest.java:39)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[error]     at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[error]     at java.lang.reflect.Method.invoke(Method.java:566)
[error]     ...

[LukaszKontowski]

Tests do not finish after 45 minutes of processing.

[LukaszKontowski]

Main issue is java.net.SocketTimeoutException: Accept timed out from https://github.com/VirtusLab/ide-probe/blob/master/core/driver/sources/src/main/scala/org/virtuslab/ideprobe/ide/intellij/InstalledIntelliJ.scala#L57

[PawelLipski]

One more thing... can you check what the IDE process (which IIUC is supposed to respond on socket but does not) is doing while ProbeDriverJavaTest is waiting for response? Just a thread dump from jstack should be enough for the start

[LukaszKontowski]

For the driver_2_13 / test command - 20 out of 23 tests succeed. Three failing tests are as follows: shutdownsLauncherAfterTest removesDirectoriesAfterRunTest removesDirectoriesEvenAfterFailureToRunIntelliJ from the https://github.com/VirtusLab/ide-probe/blob/master/core/driver/sources/src/test/scala/org/virtuslab/ideprobe/dependencies/SingleRunFixtureTest.scala test class.

Stack traces for these 3 failing tests:

[error] Test org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.removesDirectoriesEvenAfterFailureToRunIntelliJ failed: java.lang.AssertionError: Expected instances directory cleanup, but /var/folders/6j/141ys4_178d0r360cfsvg7g40000gn/T/ide-probe/instances/intellij-instance-212.5080.55--kR2vuTqaQZqcvBp861TLGw were not removed, took 38.922 sec
[error]     at org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.removesDirectoriesEvenAfterFailureToRunIntelliJ(SingleRunFixtureTest.scala:82)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[error]     at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[error]     at java.lang.reflect.Method.invoke(Method.java:568)
[error]     ...
[error] Test org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.removesDirectoriesAfterRunTest failed: java.net.SocketTimeoutException: Accept timed out, took 38.939 sec
[error]     at sun.nio.ch.NioSocketImpl.timedAccept(NioSocketImpl.java:708)
[error]     at sun.nio.ch.NioSocketImpl.accept(NioSocketImpl.java:752)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:675)
[error]     at java.net.ServerSocket.platformImplAccept(ServerSocket.java:641)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:617)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:574)
[error]     at java.net.ServerSocket.accept(ServerSocket.java:532)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.$anonfun$startIn$1(InstalledIntelliJ.scala:57)
[error]     at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:57)
[error]     at scala.concurrent.package$.blocking(package.scala:146)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.startIn(InstalledIntelliJ.scala:57)
[error]     at org.virtuslab.ideprobe.IntelliJFixture.startIntelliJ(IntelliJFixture.scala:102)
[error]     at org.virtuslab.ideprobe.SingleRunIntelliJ.apply(DSL.scala:44)
[error]     at org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.removesDirectoriesAfterRunTest(SingleRunFixtureTest.scala:46)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[error]     at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[error]     at java.lang.reflect.Method.invoke(Method.java:568)
[error]     ...
[error] Test org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.shutdownsLauncherAfterTest failed: java.net.SocketTimeoutException: Accept timed out, took 38.065 sec
[error]     at sun.nio.ch.NioSocketImpl.timedAccept(NioSocketImpl.java:708)
[error]     at sun.nio.ch.NioSocketImpl.accept(NioSocketImpl.java:752)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:675)
[error]     at java.net.ServerSocket.platformImplAccept(ServerSocket.java:641)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:617)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:574)
[error]     at java.net.ServerSocket.accept(ServerSocket.java:532)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.$anonfun$startIn$1(InstalledIntelliJ.scala:57)
[error]     at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:57)
[error]     at scala.concurrent.package$.blocking(package.scala:146)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.startIn(InstalledIntelliJ.scala:57)
[error]     at org.virtuslab.ideprobe.IntelliJFixture.startIntelliJ(IntelliJFixture.scala:102)
[error]     at org.virtuslab.ideprobe.SingleRunIntelliJ.apply(DSL.scala:44)
[error]     at org.virtuslab.ideprobe.dependencies.SingleRunFixtureTest.shutdownsLauncherAfterTest(SingleRunFixtureTest.scala:34)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[error]     at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[error]     at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[error]     at java.lang.reflect.Method.invoke(Method.java:568)
[error]     ...

[PawelLipski]

TBD if the failures of removesDirectoriesAfterRunTest and shutdownsLauncherAfterTest are independent of the failure in removesDirectoriesEvenAfterFailureToRunIntelliJ, or just a consequence of some unclean state (?) following the failure in removesDirectoriesEvenAfterFailureToRunIntelliJ

[LukaszKontowski]

Running removesDirectoriesEvenAfterFailureToRunIntelliJ alone also ends with the same failure.

TBD if the failures of removesDirectoriesAfterRunTest and shutdownsLauncherAfterTest are independent of the failure in removesDirectoriesEvenAfterFailureToRunIntelliJ, or just a consequence of some unclean state (?) following the failure in removesDirectoriesEvenAfterFailureToRunIntelliJ

Sure - work in progress

[LukaszKontowski]

Running removesDirectoriesAfterRunTest or shutdownsLauncherAfterTest alone (as the only running test) ends with the same failure. The most common part of stack trace for all failing tests is as follows:

failed: java.net.SocketTimeoutException: Accept timed out, took 38.065 sec
[error]     at sun.nio.ch.NioSocketImpl.timedAccept(NioSocketImpl.java:708)
[error]     at sun.nio.ch.NioSocketImpl.accept(NioSocketImpl.java:752)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:675)
[error]     at java.net.ServerSocket.platformImplAccept(ServerSocket.java:641)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:617)
[error]     at java.net.ServerSocket.implAccept(ServerSocket.java:574)
[error]     at java.net.ServerSocket.accept(ServerSocket.java:532)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.$anonfun$startIn$1(InstalledIntelliJ.scala:57)
[error]     at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:57)
[error]     at scala.concurrent.package$.blocking(package.scala:146)
[error]     at org.virtuslab.ideprobe.ide.intellij.InstalledIntelliJ.startIn(InstalledIntelliJ.scala:57)
[error]     at org.virtuslab.ideprobe.IntelliJFixture.startIntelliJ(IntelliJFixture.scala:102)
[error]     at org.virtuslab.ideprobe.SingleRunIntelliJ.apply(DSL.scala:44)

And such exceptions occur only on macOs - not on a linux-based OS.

[LukaszKontowski]

Setting this issue ON HOLD. To be continued after both following PRs will be merged:

• https://github.com/VirtusLab/ide-probe/pull/283
• https://github.com/VirtusLab/ide-probe/pull/275

Then it should be possible to fix that by installing intellij from .dmg file (so, probably we should set the probe.intellij.version.ext dynamically - .dmg for MacOS and .zip otherwise) and maybe something more (tested locally - changes from both mentioned PRs are in fact crucial for fixing this issue).

[LukaszKontowski]

Update: both mentioned PRs are merged 🍾 Now 3 out of 4 tests from SingleRunFixtureTest do succeed if we switch from using .zip to use .dmg extension of IntelliJ. The one failing test is removesDirectoriesEvenAfterFailureToRunIntelliJ. So, to be done:

1. fix this one failing test so that all tests succeed when .dmg is used to install IntelliJ (easier part)
2. fix installation logic so that tests succeed also with .zip

[LukaszKontowski]

For now SingleRunFixtureTest succeeds if we switch from using .zip to use .dmg extension of IntelliJ. However, there are some more tests that do not succeed even if dmg is used. This issue should be kept alive until whole sbt test can be run successfully on macOs.