8324672: Update jdk/java/time/tck/java/time/TCKInstant.java now() to be more robust #21413

rsunderbabu · 2024-10-08T17:10:43Z

The time difference check might fail for scenarios such as batch compilation. It is safer to give a bigger allowance of 10 seconds instead of 0.1 sec.

Testing: The test was run for 100 times with -Xcomp option.

Progress

Change must be properly reviewed (1 review required, with at least 1 Reviewer)
Change must not contain extraneous whitespace
Commit message must refer to an issue

Issue

JDK-8324672: Update jdk/java/time/tck/java/time/TCKInstant.java now() to be more robust (Bug - P4)

Reviewers

Roger Riggs (@RogerRiggs - Reviewer)
Daniel Fuchs (@dfuch - Reviewer)

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.org/jdk.git pull/21413/head:pull/21413
$ git checkout pull/21413

Update a local copy of the PR:
$ git checkout pull/21413
$ git pull https://git.openjdk.org/jdk.git pull/21413/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 21413

View PR using the GUI difftool:
$ git pr show -t 21413

Using diff file

Download this PR as a diff file:
https://git.openjdk.org/jdk/pull/21413.diff

Webrev

Link to Webrev Comment

bridgekeeper · 2024-10-08T17:11:29Z

👋 Welcome back rsunderbabu! A progress list of the required criteria for merging this PR into master will be added to the body of your pull request. There are additional pull request commands available for use with this pull request.

openjdk · 2024-10-08T17:12:42Z

@rsunderbabu This change now passes all automated pre-integration checks.

ℹ️ This project also has non-automated pre-integration requirements. Please see the file CONTRIBUTING.md for details.

After integration, the commit message for the final commit will be:

8324672: Update jdk/java/time/tck/java/time/TCKInstant.java now() to be more robust

Reviewed-by: rriggs, dfuchs

You can use pull request commands such as /summary, /contributor and /issue to adjust it as needed.

At the time when this comment was updated there had been 101 new commits pushed to the master branch:

b9cabbe: 8341997: Tests create files in src tree instead of scratch dir
5eae20f: 8323672: Suppress unwanted autoconf added flags in CC and CXX
6ed6dff: 8341871: Disable G1 for unsupported platforms after JDK-8334060
54c9348: 8336103: Clean up confusing Method::is_initializer
2c0c653: 8342044: Increase timeout of gc/shenandoah/oom/TestClassLoaderLeak.java
df7d6e0: 8338603: DiagnosticCommandMBean operations should standardize types for parameters
c9a536c: 8337339: gc/arguments/Test*SizeFlags.java timing out with Xcomp
f4dccfd: 8338596: Clarify handling of restricted and caller-sensitive methods
3b8a2f8: 8337269: G1ConfidencePercent interpreted inconsistently
521effe: 8340189: 8339531 incorrect for Big Endian platforms
... and 91 more: https://git.openjdk.org/jdk/compare/57c859e4adfedc963b1f4b3bf066453ace41ee36...master

As there are no conflicts, your changes will automatically be rebased on top of these commits when integrating. If you prefer to avoid this automatic rebasing, please check the documentation for the /integrate command for further details.

As you do not have Committer status in this project an existing Committer must agree to sponsor your change. Possible candidates are the reviewers of this PR (@RogerRiggs, @dfuch) but any other Committer may sponsor as well.

➡️ To flag this PR as ready for integration with the above commit message, type /integrate in a new comment. (Afterwards, your sponsor types /sponsor in a new comment to perform the integration).

openjdk · 2024-10-08T17:13:36Z

@rsunderbabu The following label will be automatically applied to this pull request:

core-libs

When this pull request is ready to be reviewed, an "RFR" email will be sent to the corresponding mailing list. If you would like to change these labels, use the /label pull request command.

mlbridge · 2024-10-08T17:16:09Z

Webrevs

RogerRiggs · 2024-10-08T19:50:54Z

test/jdk/java/time/tck/java/time/TCKInstant.java

        Instant test = Instant.now();
        long diff = Math.abs(test.toEpochMilli() - expected.toEpochMilli());
-        assertTrue(diff < 100);  // less than 0.1 secs
+        assertTrue(diff < 10_000);  // less than 10 secs


Given arbitrary delays between the two executions; the premise of the test itself is suspect; especially if the allowed time is increased. I think the test is supposed to be testing that the default clock for Instant.now() is the SystemUTC clock.
I'd expect expected to be less than or equal to test.
The use of math.abs allows the clock to go backwards; that might happen if the time was re-set manually.

Thanks @RogerRiggs for the comments. I increased the diff allowance to absorb any compilation related delays. What would you propose here?

If your objection is primarily on Math.abs, is this ok?
long diff = test.toEpochMilli() - expected.toEpochMilli(); assertTrue(diff >= 0 && diff < 10_000); // less than 10 secs

I don't think there is any way to meaningfully and reliably test the assertion that Instant.now() is the using the same clock as Instant.now(Clock.systemUTC()) given the potential delays in execution of the two statements.
It might be possible to ignore well known delays due to gc or compilation by making sure the code is warmed up by repeating the test until the delta meets the .1 sec limit. If it was really a bug, the test would timeout after a couple of minutes. Putting a while loop around the body of the test would cover that.
I'd leave the code using abs alone to avoid exposing some other unanticipated change.

I am keeping the timeout as 60 seconds. is this ok?

@Test(timeOut=60000) public void now() { Instant expected, test; long diff; do { expected = Instant.now(Clock.systemUTC()); test = Instant.now(); diff = Math.abs(test.toEpochMilli() - expected.toEpochMilli()); } while( diff > 100 ); // retry if more than 0.1 sec }

Yes, looks fine; The normal JTREG timeout is 2 minutes. 60 seconds is fine for the testng timeout.

FWIW - when I updated the System UTC clock to get sub-milliseconds resolution from the OS I added this test:
https://github.com/openjdk/jdk/blob/master/test/jdk/java/time/test/java/time/TestClock_System.java

Maybe some similar technique could be used here. That is - take System.currentTimeMillis(), Take Instant.now(), take System.currentTimeMillis() again, and then verify that the instant lies between the two snapshots: greater or equal to the first, less or equal to the second. That should always be true (unless the UTC clock is adjusted by NTP). But you could hopefully detect that and retry if you observe that the second call to System.currentTimeMillis() has returned a value which is before the first call.

If the difference between the two System::curentTimeMillis calls is too big, then if you wish you might want to try again too.

I believe this would provide a more robust test strategy.

rsunderbabu · 2024-10-10T06:01:50Z

Background of the issue:

        Instant expected = Instant.now(Clock.systemUTC());
        Instant test = Instant.now();
        long diff = Math.abs(test.toEpochMilli() - expected.toEpochMilli());
        assertTrue(diff < 100);  // less than 0.1 secs

In normal cases, the difference between the test and expected stay within the threshold of 100ms.
Issue happens when the code is run with compilation options such as -Xcomp, -Xbatch etc. The aggressive JIT optimizations and other stop-the-world pauses introduce delay in execution and the difference ends up more than 100ms.
The difference is increased to 10s to account for such delays.

dfuch · 2024-10-15T13:08:37Z

test/jdk/java/time/tck/java/time/TCKInstant.java

+            beforeMillis = Instant.now(Clock.systemUTC()).toEpochMilli();
+            instantMillis = Instant.now().toEpochMilli();
+            afterMillis = Instant.now(Clock.systemUTC()).toEpochMilli();
+            diff = instantMillis - beforeMillis;


Alternatively, you could set:

diff = afterMillis - beforeMillis; (range should be < 100ms, instant is anyhwere inside) or,

diff = Math.abs(afterMillis / 2 - instantMillis + beforeMillis / 2); (distance from instant to midpoint should be < 100ms)

Not that it matters much I guess - but it would give more symmetry... Feel free to ignore :-)

AFAIU, the original intention of the test is to check if Instant.now and Instant.now(Clock.systemUTC()) returns almost same time since the underlying clock is same.
Given that premise,
suggestion 1: it does the job but doesn't show the intention in a better way.
suggestion 2: it is not same as what the test wanted to check.
If you are fine, I would like to retain the logic I have in my latest commit.

I am fine with it.

Thanks @dfuch

RogerRiggs

LGTM

rsunderbabu · 2024-10-16T00:29:59Z

/integrate

openjdk · 2024-10-16T00:30:52Z

@rsunderbabu
Your change (at version 8a96311) is now ready to be sponsored by a Committer.

jaikiran · 2024-10-16T06:52:02Z

Roger and Daniel have reviewed this PR, I'll go ahead and sponsor this now.

jaikiran · 2024-10-16T06:52:11Z

/sponsor

openjdk · 2024-10-16T06:52:48Z

Going to push as commit e94e3bb.
Since your change was applied there have been 103 commits pushed to the master branch:

6d7e679: 8340790: Open source several AWT Dialog tests - Batch 4
86ce19e: 8341142: Maintain a single source file for sun.net.www.protocol.jar.JarFileFactory
b9cabbe: 8341997: Tests create files in src tree instead of scratch dir
5eae20f: 8323672: Suppress unwanted autoconf added flags in CC and CXX
6ed6dff: 8341871: Disable G1 for unsupported platforms after JDK-8334060
54c9348: 8336103: Clean up confusing Method::is_initializer
2c0c653: 8342044: Increase timeout of gc/shenandoah/oom/TestClassLoaderLeak.java
df7d6e0: 8338603: DiagnosticCommandMBean operations should standardize types for parameters
c9a536c: 8337339: gc/arguments/Test*SizeFlags.java timing out with Xcomp
f4dccfd: 8338596: Clarify handling of restricted and caller-sensitive methods
... and 93 more: https://git.openjdk.org/jdk/compare/57c859e4adfedc963b1f4b3bf066453ace41ee36...master

Your commit was automatically rebased without conflicts.

openjdk · 2024-10-16T06:53:05Z

@jaikiran @rsunderbabu Pushed as commit e94e3bb.

💡 You may see a message that your pull request was closed with unmerged commits. This can be safely ignored.

initial commit

a84e4fc

openjdk bot added the rfr Pull request is ready for review label Oct 8, 2024

openjdk bot added the core-libs core-libs-dev@openjdk.org label Oct 8, 2024

RogerRiggs reviewed Oct 8, 2024

View reviewed changes

rsunderbabu added 2 commits October 11, 2024 01:29

retry till timeout

c099845

checking if time is monotonic

8a96311

dfuch reviewed Oct 15, 2024

View reviewed changes

RogerRiggs approved these changes Oct 15, 2024

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Oct 15, 2024

dfuch approved these changes Oct 15, 2024

View reviewed changes

openjdk bot added the sponsor Pull request is ready to be sponsored label Oct 16, 2024

openjdk bot added the integrated Pull request has been integrated label Oct 16, 2024

openjdk bot closed this Oct 16, 2024

openjdk bot removed ready Pull request is ready to be integrated rfr Pull request is ready for review sponsor Pull request is ready to be sponsored labels Oct 16, 2024

rsunderbabu deleted the 8324672 branch October 21, 2024 04:07

8324672: Update jdk/java/time/tck/java/time/TCKInstant.java now() to be more robust #21413

8324672: Update jdk/java/time/tck/java/time/TCKInstant.java now() to be more robust #21413

Uh oh!

Conversation

rsunderbabu commented Oct 8, 2024 • edited by openjdk bot Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Progress

Issue

Reviewers

Reviewing

Webrev

Uh oh!

bridgekeeper bot commented Oct 8, 2024

Uh oh!

openjdk bot commented Oct 8, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

openjdk bot commented Oct 8, 2024

Uh oh!

mlbridge bot commented Oct 8, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Webrevs

Uh oh!

RogerRiggs Oct 8, 2024

Choose a reason for hiding this comment

Uh oh!

rsunderbabu Oct 9, 2024

Choose a reason for hiding this comment

Uh oh!

rsunderbabu Oct 9, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

RogerRiggs Oct 10, 2024

Choose a reason for hiding this comment

Uh oh!

rsunderbabu Oct 10, 2024

Choose a reason for hiding this comment

Uh oh!

RogerRiggs Oct 10, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

dfuch Oct 11, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

rsunderbabu commented Oct 10, 2024

Uh oh!

dfuch Oct 15, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

rsunderbabu Oct 15, 2024

Choose a reason for hiding this comment

Uh oh!

dfuch Oct 15, 2024

Choose a reason for hiding this comment

Uh oh!

rsunderbabu Oct 15, 2024

Choose a reason for hiding this comment

Uh oh!

RogerRiggs left a comment

Choose a reason for hiding this comment

Uh oh!

rsunderbabu commented Oct 16, 2024

Uh oh!

openjdk bot commented Oct 16, 2024

Uh oh!

jaikiran commented Oct 16, 2024

Uh oh!

jaikiran commented Oct 16, 2024

Uh oh!

openjdk bot commented Oct 16, 2024

Uh oh!

openjdk bot commented Oct 16, 2024

Uh oh!

Reviewers

Assignees

Labels

rsunderbabu commented Oct 8, 2024 •

edited by openjdk bot

Loading

openjdk bot commented Oct 8, 2024 •

edited

Loading

mlbridge bot commented Oct 8, 2024 •

edited

Loading

rsunderbabu Oct 9, 2024 •

edited

Loading

RogerRiggs Oct 10, 2024 •

edited

Loading

dfuch Oct 11, 2024 •

edited

Loading

dfuch Oct 15, 2024 •

edited

Loading