Skip to content

8285956: (fs) Excessive default poll interval in PollingWatchService #8479

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed

Conversation

backwaterred
Copy link
Contributor

@backwaterred backwaterred commented Apr 30, 2022

PollingWatchService.java contains the WatchService and WatchKey implementation for AIX and BSD. When a Path is registered this implementation creates a polling thread to monitor for file system changes. Currently, this thread waits 10 seconds before it's first poll, and then waits 10 seconds between subsequent polls. This interval leads to sluggish performance.

This PR makes the following changes:

  • Sets the initial interval to 1 second regardless of the period.
  • Change the default period to 1 second.

All tests in test/jdk/java/nio/file/WatchService passing.


Progress

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

Issue

  • JDK-8285956: (fs) Excessive default poll interval in PollingWatchService

Reviewers

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.java.net/jdk pull/8479/head:pull/8479
$ git checkout pull/8479

Update a local copy of the PR:
$ git checkout pull/8479
$ git pull https://git.openjdk.java.net/jdk pull/8479/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 8479

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

Using diff file

Download this PR as a diff file:
https://git.openjdk.java.net/jdk/pull/8479.diff

@bridgekeeper
Copy link

bridgekeeper bot commented Apr 30, 2022

👋 Welcome back backwaterred! 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 openjdk bot added the rfr Pull request is ready for review label Apr 30, 2022
@openjdk
Copy link

openjdk bot commented Apr 30, 2022

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

  • nio

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.

@openjdk openjdk bot added the nio nio-dev@openjdk.org label Apr 30, 2022
@mlbridge
Copy link

mlbridge bot commented Apr 30, 2022

@backwaterred backwaterred changed the title 8285956: [AIX, BSD] Excessive default poll interval in PollingWatchService.java 8285956: (fs) Excessive default poll interval in PollingWatchService.java May 2, 2022
@backwaterred backwaterred changed the title 8285956: (fs) Excessive default poll interval in PollingWatchService.java 8285956: (fs) Excessive default poll interval in PollingWatchService May 2, 2022
@backwaterred
Copy link
Contributor Author

/label add core-libs

@openjdk openjdk bot added the core-libs core-libs-dev@openjdk.org label May 2, 2022
@openjdk
Copy link

openjdk bot commented May 2, 2022

@backwaterred
The core-libs label was successfully added.

@bplb
Copy link
Member

bplb commented May 2, 2022

Do you have any performance measurements to share?

Note that the sensitivity can be set as shown in the SensitivityModifier test.

@AlanBateman
Copy link
Contributor

/label remove core-libs

@AlanBateman
Copy link
Contributor

/label add nio

@openjdk openjdk bot removed the core-libs core-libs-dev@openjdk.org label May 2, 2022
@openjdk
Copy link

openjdk bot commented May 2, 2022

@AlanBateman
The core-libs label was successfully removed.

@openjdk
Copy link

openjdk bot commented May 2, 2022

@AlanBateman The nio label was already applied.

@backwaterred
Copy link
Contributor Author

backwaterred commented May 2, 2022

Do you have any performance measurements to share?

Nothing terribly rigorous, but the testing I did during development went from a 11.5 sec average down to about 1.5 seconds. Which is more or less what I expected when dropping a 10 second wait ;-)

Note that the sensitivity can be set as shown in the SensitivityModifier test.

👍 Thanks for the link. I noticed it could be changed, but 10s still feels way too long for a default value.

@backwaterred
Copy link
Contributor Author

@AlanBateman Is there a guide to choosing which label is appropriate for a given change? I haven't been able to find one.

@bplb
Copy link
Member

bplb commented May 2, 2022

@AlanBateman Is there a guide to choosing which label is appropriate for a given change? I haven't been able to find one.

I think the problem was that the Jira issue had no subcomponent listed.

@bplb
Copy link
Member

bplb commented May 2, 2022

Do you have any performance measurements to share?

Nothing terribly rigorous, but the testing I did during development went from a 11.5 sec average down to about 1.5 seconds. Which is more or less what I expected when dropping a 10 second wait ;-)

Note that the sensitivity can be set as shown in the SensitivityModifier test.

👍 Thanks for the link. I noticed it could be changed, but 10s still feels way too long for a default value.

Could you perhaps test it with something a bit less aggressive than 1s, perhaps 5s? Thanks.

@backwaterred
Copy link
Contributor Author

Could you perhaps test it with something a bit less aggressive than 1s, perhaps 5s? Thanks.

Are you meaning to suggest a different default value? I recognize that my choice of 1s is arbitrary, and can change it if desired.
My thinking is that 1s is quite long to a computer, and shouldn't cause too much additional load. In addition, anything more than 2s or so is a pretty long time for a 21st century human to wait. So either 1 or 2 seconds should be the sweet spot.

Testing with initial interval of 5s yields 6.44s with my development test.

@bplb
Copy link
Member

bplb commented May 2, 2022

Could you perhaps test it with something a bit less aggressive than 1s, perhaps 5s? Thanks.

Are you meaning to suggest a different default value? I recognize that my choice of 1s is arbitrary, and can change it if desired. My thinking is that 1s is quite long to a computer, and shouldn't cause too much additional load. In addition, anything more than 2s or so is a pretty long time for a 21st century human to wait. So either 1 or 2 seconds should be the sweet spot.

Testing with initial interval of 5s yields 6.44s with my development test.

Yes, I was thinking of a different default value. Subjectively 6.44s does seem rather slow however. I know this is hard to measure in any kind of rigorous way, and the current 10s is really bad. I think the concern would be if there were many simultaneous watch services with frequent polling causing an overall performance degradation.

@backwaterred
Copy link
Contributor Author

I agree it is good to consider whether or not the design makes it easy to load up so many changes that performance degrades. But I think we're well clear of that point even with 1s. I think it helps that scheduleAtFixedRate guarantees that the tasks will not run concurrently and Watchable specifies that the key should only be created if one doesn't already exist.

If a user were to register enough unique Watchable objects to degrade the performance of their system, I am hopeful that the reason for the slow down would be clear to them.

An alternative would be to keep the initial wait at 1s and increase the default polling interval to 2s.

@bplb
Copy link
Member

bplb commented May 3, 2022

An alternative would be to keep the initial wait at 1s and increase the default polling interval to 2s.

That might be better.

A more ideal way to fix this would be to implement something on top of inotify(), kqueue(), or whatever similar native system mechanism exists on AIX.

@backwaterred backwaterred force-pushed the ExcessivePollInterval branch from 696e1ee to fc6a65d Compare May 3, 2022 13:51
@backwaterred
Copy link
Contributor Author

An alternative would be to keep the initial wait at 1s and increase the default polling interval to 2s.

That might be better.

I made this change.

A more ideal way to fix this would be to implement something on top of inotify(), kqueue(), or whatever similar native system mechanism exists on AIX.

Agreed. I have adding an implementation on top of AIX Event Infrastructure on my to-do list, but this easy fix that will address my current problem.

@backwaterred
Copy link
Contributor Author

Thanks for your comments @bplb and @AlanBateman.

If you have no further comments, and are happy with the ones I've resolved, please finalize your reviews so that I may merge (I am eager to get this one in so that I can backport it).

Copy link
Member

@tstuefe tstuefe left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks reasonable to me. I agree the default of 2secs is fine for most scenarios. If someone wants to saturate the Watchservice, he will manage to do that, but as Tyler wrote, it is an obvious problem.

Cheers, Thomas

@openjdk
Copy link

openjdk bot commented May 4, 2022

@backwaterred 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:

8285956: (fs) Excessive default poll interval in PollingWatchService

Reviewed-by: stuefe, bpb

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 72 new commits pushed to the master branch:

  • df8c2be: 8279598: Provide adapter from RandomGenerator to Random
  • 497a94f: 8286138: ProblemList javax/swing/JInternalFrame/8146321/JInternalFrameIconTest.java on macosx-aarch64
  • 7b7207a: 8280003: C1: Reconsider uses of logical_and immediates in LIRGenerator::do_getObjectSize
  • 17cc713: 8274112: (fc) Tune FileChannel.transferTo()
  • 7424f47: 8286114: [test] show real exception in bomb call in sun/rmi/runtime/Log/checkLogging/CheckLogging.java
  • 29c2e54: 8286092: Remove dead windows stack code
  • 4e1e76a: 8278757: [s390] Implement AES Counter Mode Intrinsic
  • 4b2c822: 8282477: [x86, aarch64] vmassert(_last_Java_pc == NULL, "already walkable"); fails with async profiler
  • ca9d039: 8285934: Remove unimplemented MemTracker::init_tracking_level
  • 0462d5a: 8285452: Add a new test library API to replace a file content using FileUtils.java
  • ... and 62 more: https://git.openjdk.java.net/jdk/compare/bba456a8dbf9027e4b015567c17a79fc7441aa08...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 (@tstuefe, @bplb) 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 openjdk bot added the ready Pull request is ready to be integrated label May 4, 2022
Copy link
Member

@bplb bplb left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Might be better if both constants were on PollingWatchService but this is all right.

@backwaterred
Copy link
Contributor Author

Thanks @tstuefe!

/integrate

@openjdk openjdk bot added the sponsor Pull request is ready to be sponsored label May 4, 2022
@openjdk
Copy link

openjdk bot commented May 4, 2022

@backwaterred
Your change (at version 6328307) is now ready to be sponsored by a Committer.

@openjdk openjdk bot removed the sponsor Pull request is ready to be sponsored label May 4, 2022
@backwaterred
Copy link
Contributor Author

Testing complete. We are (again) ready to...
/integrate

@openjdk openjdk bot added the sponsor Pull request is ready to be sponsored label May 4, 2022
@openjdk
Copy link

openjdk bot commented May 4, 2022

@backwaterred
Your change (at version 717dfac) is now ready to be sponsored by a Committer.

@tstuefe
Copy link
Member

tstuefe commented May 5, 2022

/sponsor

@openjdk
Copy link

openjdk bot commented May 5, 2022

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

Your commit was automatically rebased without conflicts.

@openjdk openjdk bot added the integrated Pull request has been integrated label May 5, 2022
@openjdk openjdk bot closed this May 5, 2022
@openjdk 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 May 5, 2022
@openjdk
Copy link

openjdk bot commented May 5, 2022

@tstuefe @backwaterred Pushed as commit 1bb4de2.

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

@@ -61,6 +61,11 @@
class PollingWatchService
extends AbstractWatchService
{
// Wait between polling thread creation and first poll (seconds)
private static final int POLLING_INIT_DELAY = 1;
// Default time between polls (seconds)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for more the constant. You can insert a blank line between them to make it easier to distinguish and also to keep it consistent with the existing code.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
integrated Pull request has been integrated nio nio-dev@openjdk.org
Development

Successfully merging this pull request may close these issues.

4 participants