CI: FileWatching error on macOS

[StefanKarpinski]

For example: https://travis-ci.org/JuliaLang/julia/jobs/362508394

[vtjnash]

I think the test is probably just too strict, and needs someone to look into it and decide on the appropriate resolution.

[ViralBShah]

FWIW, I have seen it on my mac locally a few times too.

[staticfloat]

It looks like the issue is that the events we're getting are out-of-order;

Some tests did not pass: 473 passed, 5 failed, 0 errored, 0 broken.FileWatching: Test Failed at /private/tmp/julia/share/julia/site/v0.7/FileWatching/test/runtests.jl:401
  Expression: pop!(changes) == (F_PATH => FileWatching.FileEvent(FileWatching.UV_RENAME))
   Evaluated: "afile.txt3" => FileWatching.FileEvent(true, false, false) == "afile.txt" => FileWatching.FileEvent(true, false, false)
FileWatching: Test Failed at /private/tmp/julia/share/julia/site/v0.7/FileWatching/test/runtests.jl:405
  Expression: pop!(changes) == (F_PATH * "~" => FileWatching.FileEvent(FileWatching.UV_RENAME))
   Evaluated: "afile.txt2" => FileWatching.FileEvent(true, false, false) == "afile.txt~" => FileWatching.FileEvent(true, false, false)
FileWatching: Test Failed at /private/tmp/julia/share/julia/site/v0.7/FileWatching/test/runtests.jl:417
  Expression: pop!(changes) == ("$(F_PATH)$(i)" => FileWatching.FileEvent(FileWatching.UV_RENAME))
   Evaluated: "afile.txt" => FileWatching.FileEvent(false, true, false) == "afile.txt3" => FileWatching.FileEvent(true, false, false)
FileWatching: Test Failed at /private/tmp/julia/share/julia/site/v0.7/FileWatching/test/runtests.jl:417
  Expression: pop!(changes) == ("$(F_PATH)$(i)" => FileWatching.FileEvent(FileWatching.UV_RENAME))
   Evaluated: "afile.txt" => FileWatching.FileEvent(false, true, false) == "afile.txt2" => FileWatching.FileEvent(true, false, false)
FileWatching: Test Failed at /private/tmp/julia/share/julia/site/v0.7/FileWatching/test/runtests.jl:417
  Expression: pop!(changes) == ("$(F_PATH)$(i)" => FileWatching.FileEvent(FileWatching.UV_RENAME))
   Evaluated: "afile.txt" => FileWatching.FileEvent(false, true, false) == "afile.txt1" => FileWatching.FileEvent(true, false, false)

[StefanKarpinski]

Interesting. So maybe we could collect them and then check that the set of notifications is correct?

[staticfloat]

It seems to me that the design of the tests is very purposeful that the events should come in in-order. My best guess is that OSX may have a "granularity" at which new events come in, and within a bin, events are not guaranteed to be ordered. I know that OSX filesystems have a timestamp granularity of 1s; that doesn't necessarily mean anything here, but it gives me pause.

[StefanKarpinski]

If the OS doesn't guarantee ordering of events, then we can expect it in our tests...

[mbauman]

This was an optimistic close. Let's keep a close eye on things here and re-open if we still see trouble.

[martinholters]

Just seen again: https://travis-ci.org/JuliaLang/julia/jobs/396739198

[quinnj]

And here: https://travis-ci.org/JuliaLang/julia/jobs/396696820

[timholy]

For what it's worth, OSX was a major pain for Revise, which uses FileWatching heavily. To prevent test failures it now compares mtimes with an insane amount of slop

if mtime(path) + 1 >= floor(wf.timestamp) # OSX rounds mtime up, see #22

and after creating a new file the tests sleep 2.1 seconds before setting up watching (partly to overcome this slop). After triggering watching on a file, Revise's tests also wait 0.1 seconds before doing anything that depends on watching actually working. (On Linux, you could divide all these numbers by 10 and you'd be fine.) You can search https://github.com/timholy/Revise.jl/blob/master/test/runtests.jl for sleep to see more concrete details.

Also, Revise's tests use this heavily:

@static if Sys.isapple()
    yry() = (sleep(1.1); revise(); sleep(1.1))
else
    yry() = (sleep(0.1); revise(); sleep(0.1))
end

[vtjnash]

My understanding is that this is one of the contributing factors in the switch to APFS and that the Revise.jl issue should start to go away in another year or so

[KristofferC]

Closing in favour of #28430.