search

Karm / mandrel-integration-tests

Integration tests for GraalVM and its Mandrel distribution. Runs Quarkus, Helidon and Micronaut applications and small targeted reproducers. The focus is solely on native-image utility and compilation of Java applications into native executables.
Apache License 2.0
5 stars 3 forks source link

[23.1] Windows randomNumbers (wrongly?) failing in Jenkins #216

Open jerboaa opened 8 months ago

jerboaa commented 8 months ago

We see the Mandrel IT test randomNumbersReinit failing. Likely a false positive since we don't see the same test failing in GHA.

The Jenkins (Windows 2019k) failure looks like this:

org.opentest4j.AssertionFailedError: There should have been 4 distinct lines in the log,showing 2 different pseudorandom sequences. The fact that there are less than 4 means the native imagewas not properly re-seeded. See https://github.com/oracle/graal/issues/2265. ==> expected: <4> but was: <0>
    at org.graalvm.tests.integration.AppReproducersTest.randomNumbersReinit(AppReproducersTest.java:140)

The console output has this:

23:27:35 2023-10-11 17:27:35.386 INFO  [o.g.t.i.AppReproducersTest] (randomNumbersReinit) Running...#1
23:27:35 2023-10-11 17:27:35.387 INFO  [o.g.t.i.u.Commands] (runCommand) Command: [cmd, /C, target\random-numbers.exe]
23:27:40 2023-10-11 17:27:40.391 INFO  [o.g.t.i.AppReproducersTest] (randomNumbersReinit) Running...#2
23:27:40 2023-10-11 17:27:40.391 INFO  [o.g.t.i.u.Commands] (runCommand) Command: [cmd, /C, target\random-numbers.exe]
23:27:45 2023-10-11 17:27:45.397 INFO  [o.g.t.i.AppReproducersTest] (randomNumbersReinit) []

Yet, in GHA we see this:

[...]
2023-10-07 02:36:09.001 INFO  [o.g.t.i.AppReproducersTest] (randomNumbersReinit) Running...#1
2023-10-07 02:36:09.001 INFO  [o.g.t.i.u.Commands] (runCommand) Command: [cmd, /C, target\random-numbers.exe]
2023-10-07 02:36:09.064 INFO  [o.g.t.i.AppReproducersTest] (randomNumbersReinit) Running...#2
2023-10-07 02:36:09.064 INFO  [o.g.t.i.u.Commands] (runCommand) Command: [cmd, /C, target\random-numbers.exe]
2023-10-07 02:36:09.111 INFO  [o.g.t.i.AppReproducersTest] (randomNumbersReinit) [secureRandom: [23, 8, 44, 69, 31, 2, 78, 82, 67, 57], UUID: 64736559-7710-4346-916b-6c43a4b38599, secureRandom: [82, 90, 18, 98, 31, 40, 41, 28, 2, 77], UUID: 3e16389d-5cbb-48df-a371-65efa81c9de8]

I.e. different random numbers and UUIDs get generated.

We need to investigate why we see the failure in Jenkins. It appears we don't get any output on the Jenkins system.

jerboaa commented 8 months ago

@Karm Could you please take a look? Thanks!

Karm commented 5 months ago

@jerboaa

I did not see it, then I saw it again and now I cannot reproduce it on the very machine that acted as a Jenkins executor for it just minutes ago while testing mandrel-23.1.2.0-Final.

Recommendations:
 INIT: Adopt '--strict-image-heap' to prepare for the next GraalVM release.
 HEAP: Set max heap for improved and more predictable memory usage.
 CPU:  Enable more CPU features with '-march=native' for improved performance.
------------------------------------------------------------------------------------------------------------------------
                        3.3s (7.2% of total time) in 137 GCs | Peak RSS: 1.15GB | CPU load: 5.49
------------------------------------------------------------------------------------------------------------------------
Produced artifacts:
 C:\tmp\mandrel-integration-tests\apps\random-numbers\target\random-numbers.exe (executable)
========================================================================================================================
Finished generating 'random-numbers' in 44.8s.
2024-01-23 18:39:58.657 INFO  [o.g.t.i.AppReproducersTest] (randomNumbersReinit) Running...#1
2024-01-23 18:39:58.658 INFO  [o.g.t.i.u.Commands] (runCommand) Command: [cmd, /C, target\random-numbers.exe]
2024-01-23 18:39:58.706 INFO  [o.g.t.i.AppReproducersTest] (randomNumbersReinit) Running...#2
2024-01-23 18:39:58.706 INFO  [o.g.t.i.u.Commands] (runCommand) Command: [cmd, /C, target\random-numbers.exe]
2024-01-23 18:39:58.756 INFO  [o.g.t.i.AppReproducersTest] (randomNumbersReinit) [secureRandom: [35, 60, 38, 81, 15, 56, 84, 55, 63, 64], UUID: 75f1505e-8bb7-45fc-8375-76b74957aa75, UUID: 7ccbfe23-b33a-41ee-8d16-34282f6b6d67, secureRandom: [75, 26, 13, 2, 25, 24, 33, 2, 95, 4]]
2024-01-23 18:39:58.797 INFO  [o.g.t.i.u.Logs] (checkLog) build-and-run.log log for randomNumbersReinit contains whitelisted error: `[WARNING] system modules path not set in conjunction with -source 11'
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 56.614 s - in org.graalvm.tests.integration.AppReproducersTest
[INFO]
[INFO] Results:
[INFO]
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0
[INFO]
[INFO]
[INFO] --- jar:3.3.0:jar (default-jar) @ testsuite ---
[INFO] Building jar: C:\tmp\mandrel-integration-tests\testsuite\target\testsuite-1.0.0-SNAPSHOT.jar
[INFO]
[INFO] --- failsafe:2.22.2:integration-test (default) @ testsuite ---
[INFO]
[INFO] --- failsafe:2.22.2:verify (default) @ testsuite ---
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary for Native image integration TS 1.0.0-SNAPSHOT:
[INFO]
[INFO] Native image integration TS ........................ SUCCESS [  0.295 s]
[INFO] testsuite .......................................... SUCCESS [01:03 min]
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  01:04 min
[INFO] Finished at: 2024-01-23T18:39:59-05:00
[INFO] ------------------------------------------------------------------------
C:\tmp\mandrel-integration-tests(master -> origin)
λ native-image --version
native-image 21.0.2 2024-01-16
OpenJDK Runtime Environment Mandrel-23.1.2.0-Final (build 21.0.2+13-LTS)
OpenJDK 64-Bit Server VM Mandrel-23.1.2.0-Final (build 21.0.2+13-LTS, mixed mode)

The main difference is that the failed run was started by Jenkins and the aforementioned run by me, manually, via RDesktop.

Entropy issue? I will try to chase it down...