RFR: 8293067: (fs) Implement WatchService using system library (macOS)

[Maxim Kartashev]

On Wed, 16 Nov 2022 08:11:32 GMT, Alan Bateman <alanb at openjdk.org> wrote:

>>> In our CI system `test/jdk/java/nio/file/WatchService/Move.java` appears to time out consistently, although I have not seen it happen on my local machine.
>> 
>> I've been backed up with other things and finally getting to look at this more closely. For testing, I tried both release and debug builds across a range of macOS releases on both x64 and aarch64. Unfortunately there is a lot of timeouts and intermittent failures and across quite a range of macOS releases (from 10.15 to 12.2).
>> 
>> The most frequent failure seems to be the testOverflowEvent test in LotsOfEvents.  Here's an example failure:
>> 
>> ----------System.out:(1/47)----------
>> Seed from RandomFactory = 1932318894124342221L
>> ----------System.err:(12/655)----------
>> java.lang.RuntimeException: Key not signalled (unexpected)
>> 	at LotsOfEvents.drainAndCheckOverflowEvents(LotsOfEvents.java:105)
>> 	at LotsOfEvents.testOverflowEvent(LotsOfEvents.java:78)
>> 	at LotsOfEvents.main(LotsOfEvents.java:51)
>> 	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
>> 	at java.base/java.lang.reflect.Method.invoke(Method.java:578)
>> 	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:312)
>> 	at java.base/java.lang.Thread.run(Thread.java:1591)
>
>> @AlanBateman still can't reproduce any of that on my hardware, so I added some tracing so that next time tests are run we can at least see what's happening.
> 
> LotsOfEvents.java on macOS 12.2
> 
> ----------stdout:(7/337)----------
> WatchService: get run loop -> 600003a5c500
> WatchService: running run loop 600003a5c500
> WatchService: created event stream 101105150
> WatchService: scheduled event stream 101105150 on run loop 600003a5c500
> WatchService: running run loop 600003a5c500
> WatchService: stopped event stream 101105150
> WatchService: stopped run loop 600003a5c500
> ----------System.out:(10/421)----------
> Seed from RandomFactory = 5027502271796047304L
> WatchService: Run loop 600003a5c500 - waiting...
> WatchService: Run loop 600003a5c500 - starting...
> Test: dir.register - start
> WatchService: Run loop 600003a5c500 - waiting for event source...
> Test: dir.register - done
> WatchService: Run loop 600003a5c500 - starting...
> Test: created files
> Test: About to poll
> WatchService: Run loop 600003a5c500 - waiting for event source...
> ----------System.err:(12/655)----------
> java.lang.RuntimeException: Key not signalled (unexpected)
> 	at LotsOfEvents.drainAndCheckOverflowEvents(LotsOfEvents.java:112)
> 	at LotsOfEvents.testOverflowEvent(LotsOfEvents.java:84)
> 	at LotsOfEvents.main(LotsOfEvents.java:51)
> 	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
> 	at java.base/java.lang.reflect.Method.invoke(Method.java:578)
> 	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:312)
> 	at java.base/java.lang.Thread.run(Thread.java:1591)
> 
> JavaTest Message: Test threw exception: java.lang.RuntimeException
> JavaTest Message: shutting down test
> 
> result: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: Key not signalled (unexpected)
> 
> 
> DeleteInterference.java also  on macOS 12.2, this one is a timeout:
> 
> open 292 end
> open 293 begin
> WatchService: Run loop 6000004a9000 - waiting...
> WatchService: Run loop 6000004a9000 - starting...
> WatchService: Run loop 6000004a9000 - waiting for event source...
> open 293 end
> open 294 begin
> WatchService: Run loop 6000004ade00 - waiting...
> WatchService: Run loop 6000004ade00 - starting...
> WatchService: Run loop 6000004ade00 - waiting for event source...
> WatchService: Run loop 6000004ade00 - starting...
> WatchService: Run loop 60000
> result: Error. Agent error: java.lang.Exception: Agent 8 timed out with a timeout of 480 seconds; check console log for any additional details
> 
> test result: Error. Agent error: java.lang.Exception: Agent 8 timed out with a timeout of 480 seconds; check console log for any additional details
> 
> 
> The .jtr are huge due to all the tracing.

@AlanBateman Thank you for the log. I see all the right calls, but I don't see any events coming in from the OS.

I'm afraid this is the line beyond which I can't tread; there seem to be instances where [certain directories don't generate FSEvents](https://github.com/livereload/livereload-site/blob/master/livereload.com/_articles/troubleshooting/os-x-fsevents-bug-may-prevent-monitoring-of-certain-folders.md), there's even a [tool](https://github.com/andreyvit/find-fsevents-bugs) to find those. Unfortunately, I know nothing beyond what was said on those pages.

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

PR: https://git.openjdk.org/jdk/pull/10140