[jdk18] Integrated: 8279398: jdk/jfr/api/recording/time/TestTimeMultiple.java failed with "RuntimeException: getStopTime() > afterStop"

[Erik Gahlin]

On Thu, 6 Jan 2022 02:55:48 GMT, Erik Gahlin <egahlin at openjdk.org> wrote:

> Hi,
> 
> Could I have review of a fix of a regression introduced with "JDK-8268297: jdk/jfr/api/consumer/streaming/TestLatestEvent.java times out" https://bugs.openjdk.java.net/browse/JDK-8268297
> 
> Bumping the timestamp in native, if the timestamp has not changed, ensures that chunks gets a strictly increasing start time, which is needed for event streaming to order chunks chronologically.
> 
> Problem is that tests, and probably users as well, expect that the start/stop time of a recording never exceeds what a later invocation to Instant.now() returns, for example:
> 
> Recording a = new Recording();
> a.start(); // first chunk begins 
> a.stop(); // first chunk ends
> Recording b = new Recording();
> b.start(); // second chunk begins, where time stamp is taken and possibly bumped with a nanosecond.
> Instant now = Instant.now();
> if (now.isBefore(b.getStartTime())) {
>   System.out.println("WAT");
> }
> 
> This can happen on Windows where the clock has low resolution, so Recording::start() may finish execution without a clock change. The fix is to let methods that creates a new chunk spin until the clock has catched up.
> 
> To verify the fix, I modified the test jdk/jdk/jfr/api/recoding/time/TestTimeMultiple.java so it executes code similar to above 100 times per test and then ran the test 200 times without failures. Without the fix, failures were frequent.
> 
> Technically, it's not necessary for all places to use Utils::getChunkStartNanos() instead of JVM::getChunkStartNanos(), but it seemed more prudent to never use the low level function, which can in some circumstances lead to incorrect behavior.
> 
> Thanks
> Erik

This pull request has now been integrated.

Changeset: 40df5df9
Author:    Erik Gahlin <egahlin at openjdk.org>
URL:       https://git.openjdk.java.net/jdk18/commit/40df5df95edb67331d39d829b895094e961fe21f
Stats:     61 lines in 3 files changed: 31 ins; 23 del; 7 mod

8279398: jdk/jfr/api/recording/time/TestTimeMultiple.java failed with "RuntimeException: getStopTime() > afterStop"

Reviewed-by: mgronlun

-------------

PR: https://git.openjdk.java.net/jdk18/pull/84