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

[Michael Hall]

I think someone may of mentioned benchmarks at some point. 

My thought on a watch service to try this on was monitoring the blockchain blocks for a full bitcoin client.

It doesn’t update all that often so not really a benchmark stress test. But a pretty easy one. Run both a polling and a FSEvents service.

java SimpleBTCWatcher
WatchService sun.nio.fs.PollingWatchService at 1b6d3586
Watching for events on /Volumes/BTC/Bitcoin/blocks
ENTRY_MODIFY occurred on blk03268.dat at 1668043049779 block access time 1668042238000 block modified time 1668043049610
ENTRY_MODIFY occurred on blk03268.dat at 1668043251780 block access time 1668043050000 block modified time 1668043251540
ENTRY_MODIFY occurred on blk03268.dat at 1668043609759 block access time 1668043608000 block modified time 1668043608650
ENTRY_MODIFY occurred on blk03268.dat at 1668043813761 block access time 1668043608000 block modified time 1668043813380
ENTRY_MODIFY occurred on blk03268.dat at 1668043943766 block access time 1668043814000 block modified time 1668043943550
ENTRY_MODIFY occurred on blk03268.dat at 1668044651774 block access time 1668043944000 block modified time 1668044651360
ENTRY_MODIFY occurred on blk03268.dat at 1668045843727 block access time 1668045842000 block modified time 1668045842250
ENTRY_MODIFY occurred on blk03268.dat at 1668045955806 block access time 1668045954000 block modified time 1668045954320
ENTRY_MODIFY occurred on blk03268.dat at 1668046521801 block access time 1668045954000 block modified time 1668046520890
ENTRY_MODIFY occurred on blk03268.dat at 1668047175806 block access time 1668047174000 block modified time 1668047174070
ENTRY_MODIFY occurred on blk03268.dat at 1668047485805 block access time 1668047174000 block modified time 1668047485660
ENTRY_MODIFY occurred on blk03268.dat at 1668047815828 block access time 1668047486000 block modified time 1668047814900

/Users/mjh/Documents/GitHub/jdk/build/*/images/jdk/bin/java -Dsun.nio.fs.MacOSXWatchService.use=true SimpleBTCWatcher
WatchService sun.nio.fs.MacOSXWatchService at 5c647e05
Watching for events on /Volumes/BTC/Bitcoin/blocks
ENTRY_MODIFY occurred on blk03268.dat at 1668043050347 block access time 1668042238000 block modified time 1668043049610
ENTRY_MODIFY occurred on blk03268.dat at 1668043252163 block access time 1668043050000 block modified time 1668043251540
ENTRY_MODIFY occurred on blk03268.dat at 1668043609299 block access time 1668043608000 block modified time 1668043608650
ENTRY_MODIFY occurred on blk03268.dat at 1668043814008 block access time 1668043608000 block modified time 1668043813380
ENTRY_MODIFY occurred on blk03268.dat at 1668043944009 block access time 1668043814000 block modified time 1668043943550
ENTRY_MODIFY occurred on blk03268.dat at 1668044652033 block access time 1668043944000 block modified time 1668044651360
ENTRY_MODIFY occurred on blk03268.dat at 1668045843305 block access time 1668044652000 block modified time 1668045842250
ENTRY_MODIFY occurred on blk03268.dat at 1668045954853 block access time 1668045842000 block modified time 1668045954320
ENTRY_MODIFY occurred on blk03268.dat at 1668046521441 block access time 1668045954000 block modified time 1668046520890
ENTRY_MODIFY occurred on blk03268.dat at 1668047175552 block access time 1668047174000 block modified time 1668047174070
ENTRY_MODIFY occurred on blk03268.dat at 1668047486484 block access time 1668047174000 block modified time 1668047485660
ENTRY_MODIFY occurred on blk03268.dat at 1668047815507 block access time 1668047486000 block modified time 1668047814900

The ‘at’ is System.currentTimeMillis. Polling often faster somewhat surprisingly? 

Running jconsole on both the only really significant difference I notice is gc.  For FSEvents…

Time: 	2022-11-09 20:45:24
Used: 	           155,387 kbytes
Committed: 	   266,240 kbytes
Max: 	 4,194,304 kbytes
GC time: 	 0.021 seconds on G1 Young Generation (2 collections)         
                 0.000 seconds on G1 Old Generation (0 collections) 

And for polling…

Time: 	2022-11-09 20:46:05
Used: 	          106,701 kbytes
Committed: 	   266,240 kbytes
Max: 	 4,194,304 kbytes
GC time: 	 0.081 seconds on G1 Young Generation (51 collections)         
                 0.000 seconds on G1 Old Generation (0 collections)

Polling gc’s considerably more often and takes relatively longer doing it. Still hundredths of a second. 
A more stressful  watch service might make this difference or other ones more significant.

Have any other platform implementations been benchmarked relative to polling?