Update CI for upcoming macOS changes

[ehuss]

Azure will be removing support for macOS 10.13 in March (https://devblogs.microsoft.com/devops/azure-pipelines-hosted-pools-updates/). We will need to update our CI configuration to use the new image. This will also remove support for cross-compiling tests to i686-apple-darwin. I would like to retain some kind of cross-compile testing on macOS, and Alex suggested using wasm as the alternate target (possibly minus the cross-compile cargo run tests).

[ehuss]

I have a branch which implements this, but I am running into problems. See rust-lang/rust#68863 (comment) for details.

EDIT: Added logs here:

Logs

taskgated   11  libsystem_pthread.dylib             0x00007fff6522fe65 _pthread_start + 148
taskgated   12  libsystem_pthread.dylib             0x00007fff6522b83b thread_start + 15
taskgated   no system signature for unsigned /Users/eric/Proj/rust/cargo/target/debug/cargo[30241]
taskgated   close(3) err: 0
taskgated   end request
taskgated   begin request: 3331, 27001
taskgated   UNIX error exception: 2
opendirectoryd  PID: 30240, Client: 'clang', exited with 0 session(s), 0 node(s) and 0 active request(s)
opendirectoryd  Trigger - cancelled
opendirectoryd  Finalizing pidinfo (30240) object - 0x7fccecb44d00
taskgated   0   Security                            0x00007fff3a1fea43 Security::CommonError::LogBacktrace() + 107
taskgated   1   Security                            0x00007fff3a1fed5d Security::UnixError::UnixError(int, bool) + 263
taskgated   2   Security                            0x00007fff3a1fedb8 Security::UnixError::throwMe(int) + 36
taskgated   3   Security                            0x00007fff3a101c56 Security::CodeSigning::KernelCode::identifyGuest(Security::CodeSigning::SecCode*, __CFData const**) + 1006
taskgated   4   Security                            0x00007fff3a0df0fa Security::CodeSigning::SecCode::identify() + 58
taskgated   5   Security                            0x00007fff3a0df514 Security::CodeSigning::SecCode::autoLocateGuest(__CFDictionary const*, unsigned int) + 122
taskgated   6   Security                            0x00007fff3a0e55a6 SecCodeCopyGuestWithAttributes + 78
taskgated   7   taskgated                           0x000000010119f3b7 taskgated + 13239
taskgated   8   taskgated                           0x000000010119facb taskgated + 15051
taskgated   9   taskgated                           0x000000010119fe67 taskgated + 15975
taskgated   10  taskgated                           0x000000010119fed3 taskgated + 16083
taskgated   11  taskgated                           0x00000001011a20ea taskgated + 24810
taskgated   12  taskgated                           0x00000001011a1617 taskgated + 22039
opendirectoryd  PID: 30005, Client: 'cargo', exited with 0 session(s), 0 node(s) and 0 active request(s)
taskgated   13  taskgated                           0x00000001011a0ce5 taskgated + 19685
syspolicyd  GK process assessment:  <-- (, )
opendirectoryd  Trigger - cancelled
syspolicyd  Unable (errno: 2) to read file at  for process path:  library path: (null)
taskgated   14  libsystem_pthread.dylib             0x00007fff6522fe65 _pthread_start + 148
opendirectoryd  Finalizing pidinfo (30005) object - 0x7fccead43440
syspolicyd  Dropping com.apple.syspolicy.Gatekeeper.Errors as it isn't used in any transform (not in the config or budgeted?)
kernel  build_userspace_exit_reason: illegal flags passed from userspace (some masked off) 0x141, ns: 9, code 0x8
syspolicyd  Terminating process due to Gatekeeper rejection: 30005, 
taskgated   15  libsystem_pthread.dylib             0x00007fff6522b83b thread_start + 15
kernel  Waking up reference: 66615
taskgated   no signature for pid=30005 (cannot make code: UNIX[No such file or directory])
kernel  Thread waiting on reference 66615 woke up
taskgated   end request
kernel  Sleep interrupted, signal 0x100
kernel  Security policy would not allow process: 30005, /Users/eric/Proj/rust/cargo/target/cit/t1430/foo/target/debug/deps/foo

Most of these messages are unique to when it decides to kill a process.

[alexcrichton]

@ehuss it may be worthwhile opening an issue for that on https://github.com/actions/virtual-environments since that's probably an image thing that may need fixing?

[ehuss]

Nah, I can repro locally. I'm pretty sure it's a bug in Catalina (I wasn't able to repro in older macOS versions). Catalina had a bunch of new security changes, so it's not too surprising that a weird use case like Cargo's test suite causes a problem. I might file a radar, but in my experience it usually takes at least a few years to get a response (and since this is an obscure case, unlikely to get any response).

I'm currently leaning towards changing Cargo's testsuite to check for processes that exit with SIGKILL on macos and retrying them. I'm not sure how difficult that will be (it will probably need to scan the output for text like "exited with signal: 9").

My concern is that it would also happen with rustc's test suite, since it also rapidly creates new executables and runs them. But it seemed fine on my end, so maybe there's something unique or different in how Cargo is interacting. Or maybe Cargo's tests are more complex than rustc's, since they often have more complex linking requirements and do several rapid rebuilds of the same project (like overwriting an executable several times might confuse Gatekeeper).

[alexcrichton]

Oh jeez that's a bummer :(

I figured there was some way to disable this but it doesn't look like that's possible at least from the UI... I agree that waiting for a fix from Apple probably isn't gonna happen, but I'm surprised others haven't run into this in the sense that testing C/C++ projects (maybe even LLVM) or other big-ish build systems in general seems like they'd have the same issues.

Googling around "disable gatekeeper" it looks like there are some hits though. I've got catalina myself and I can try to play with this soon and see if those can fix the issue. My thinking is that if we could disable w/e security things are there then we could make the request to github actions to do that on their image.

[ehuss]

I tried disabling Gatekeeper with spctl --master-disable, but that didn't help. I also tried with the network turned off (thinking it might be related to the Notary service), but that didn't help either.

One thing did fix the problem, and that is disabling System Integrity Protection. That requires running csrutil disable from the Recovery OS. That seems to completely disable the syspolicyd process. I'm not sure if that's something we can ask Azure to do, since it is a manual thing that affects the entire system (and might lower their defenses). I'd also prefer not to do that on my development machines.

I could maybe run the tests in a loop and collect data about which tests seem to fail. So far it seems pretty random, but maybe there is a pattern to which ones are affected?

[ehuss]

I ran the tests in a loop for a couple hours and counted which tests failed:

4 build_script::optional_build_script_dep
3 run::run_multiple_packages
3 run::release_works
3 run::fail_no_extra_verbose
2 run::specify_name
2 run::run_workspace
2 features::all_features_virtual_ws
2 build_script::rename_with_link_search_path
2 build_script::assume_build_script_when_build_rs_present
1 standard_lib::simple_bin_std
1 run::specify_default_run
1 run::simple
1 run::run_with_library_paths
1 run::run_dylib_dep
1 run::run_bin_different_name
1 run::library_paths_sorted_alphabetically
1 run::explicit_bin_with_args
1 run::exit_code
1 run::dashes_are_forwarded
1 path::path_dep_build_cmd
1 features::default_feature_pulled_in
1 build_script::optional_build_dep_and_required_normal_dep
1 build_script::code_generation
1 build::run_proper_binary_main_rs
1 build::run_proper_binary
1 build::crate_library_path_env_var

The only commonality I see is that these all run a process after it is built.

[Mark-Simulacrum]

@ehuss Do you have a script for generating that? It might be useful to try and have others run tests locally as well, I guess, and see if we get the ~same set.

[ehuss]

I just ran while true; do cargo test --test testsuite >> log; done, and then stopped it after a few hours. Grep for "FAILED$" in the log file, and made a unique count. I did that in my editor, but grep FAILED$ log | sort | uniq -c | sort -n should be the same.

[alexcrichton]

Hm well without really knowing much about why these tests are getting killed makes it sort of hard to figure out how to work around this. We may be able to get by with a 10ms sleep before spawning processes or something like that?

The nondeterministic nature of this in particular is hard to wrap my head around. Given that I'm not sure how we can handle this because it's hard to pinpoint a cause. Clearly we can run just-generated binaries, just not in some cases...

[Mark-Simulacrum]

In the reproductions I've managed to come across locally, "syspolicyd Unable (errno: 2) to read file at for process path: library path: (null)" is a commonality -- that suggests to me that some file is perhaps not being fully created yet? Maybe we need to (loosely) fsync before running a binary?

Unfortunately it looks like locally I get the following, and turning these privates into non-private seems hard (the random blogs online suggests running reverse-engineered code, which seems... error prone, and I don't want to break something :)

syspolicyd: Unable (errno: 2) to read file at <private> for process path: <private> library path: (null)
syspolicyd: Unable (errno: 2) to read file at <private> for process path: <private> library path: (null)

Some rough googling for the error here leads me to flutter/flutter#38325 via https://github.com/christopherfujino/catalina-crasher-demo/, which has the interesting sounding:

The actual cause is calling the Flutter tool re-entrantly, which deletes the current Dart SDK (which the flutter upgrade process is using), after which any forked sub-processes would be killed (code -9 from the VersionCheckError message) by the macOS anti-malware software

That sounds at least plausibly like something that might happen to us here? I don't think we're deleting anything that is forking a subprocess off, but maybe there's a similar error condition.

[ehuss]

Yea, from what I've read (blog) it is impossible to reveal those <private> fields in 10.15.3, that's very frustrating. I'm almost tempted to figure out how to reinstall 10.15.2 to view them.

I went strolling through Apple's opensource deposits to see if any of this code is available, but they have only released the kernel for 10.15, and I can't find syspolicyd in 10.14 (I found copies from much older releases (10.7?), but that is not helpful). I found the code for build_userspace_exit_reason, but it's not too interesting (pretty much saying, it won't create a crash report).

I created an isolated reproduction that does not use cargo:

scargo.zip

It seems like calling hard_link is required to trigger the issue. If I switch that to a copy, it doesn't trigger. Maybe we'll just need to switch to copies on macos? Maybe either of you can fiddle with that repro and see if there's some other way to work around it?

[Mark-Simulacrum]

Heh, I didn't come across that particular blog! By chance, I think I'm still on .2, so I'll try that out.

I will also try to fiddle with the reproduction you've noted. Losing hard linking is actually probably not too bad, especially on Macs, where most people have ssds I'd guess (or at least fast disks).

[aidanhs]

I was trying to help someone on the users forum who had an issue with something that seems suspiciously similar - https://users.rust-lang.org/t/github-actions-randomly-kill-a-test-program/37255/