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

[Maxim Kartashev]

I benchmarked this implementation (well, the implementation this one is
based on, now it's become quite different) extensively. The main advantage
of FSEvents over polling was near-0 CPU usage when there were small number
of changes to the directory being watched, while polling naturally always
has some background job to do and its CPU usage heavily depends on refresh
speed (like 25% with SENSITIVITY_HIGH and modest rate of changes).

On Thu, Nov 10, 2022 at 6:22 AM Michael Hall <mik3hall at gmail.com> wrote:

>
> 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?
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/nio-dev/attachments/20221110/cc8922af/attachment-0001.htm>