Last year I wrote a blog post Mac app launches slowed by malware scan:
I discovered that the slow launches are caused by thesyspolicydprocess, specificallyDispatchQueue "com.apple.security.syspolicy.yara". The backtrace showedsyspolicydcalling theyr_rules_scan_filefunction.
Recently, however, voluminous blogger Howard Oakley has written a series of blog posts, starting with Why some apps launch very slowly and culminating with Why some apps sometimes launch extremely slowly, that appear to be in denial of my discovery. Oakley says,
Malware scan using any known Yara rules is most unlikely, as:
- XProtect Yara rules commonly include file size limits, resulting in few rules applying to larger files, and more rapid completion.
- Known checks using Yara rules are all well-recorded in log entries, and the source of those rules is stated clearly.
- Yara scans are normally reported with their result.
- Scan results are succinct and hardly likely to be lost in a ‘cache miss’.
I'm truly baffled by this denial, because the backtrace I mentioned comes directly from spindumps (/usr/sbin/spindump), which take frequent (10 milliseconds by default) samples of all running processes on the system. Spindumps don't lie!
The spindumps also indicate that the syspolicyd malware checks are triggered by the dlopen function to load a dynamic library. These are the framework checks that Oakley mentions; a framework is essentially bundled dynamic library. You can see the series of function calls in the samples of the launching app:
dyld4::APIs::dlopen_from(char const*, int, void*)
AppleSystemPolicy::fileCheckLibraryValidation(proc*, fileglob*, long long, long long, unsigned long)
AppleSystemPolicy::perform_malware_scan_if_necessary(ASPProcessInfo*, ASPEvaluationInfo*, int, ScanMeta*, int*, unsigned int, int, long long*)
AppleSystemPolicy::waitForEvaluation(syspolicyd_evaluation*, int, ASPEvaluationInfo*, vnode**, evaluation_results*, long long*, char const*)
It doesn't get any more obvious than perform_malware_scan_if_necessary! And the app is literally waiting for the syspolicyd evaluation, hence the slow launch.
I tried to explain this to Oakley in the comments of one of his blog posts, but for some strange reason, he refuses to accept my points. In fact, he refuses to take or to read a spindump. At first he claimed it was too difficult for anyone except an "expert" like me, but I simply selected "Spindump" from the action menu in Activity Monitor and then did a text search of the resulting file. (On the other hand, you can control the timing of the spindump more precisely using the spindump command-line tool, even specifying that it should wait for a particular app to launch.)
Oakley's position appears to be that the log messages tell him everything that he needs to know, as if a phenomenon doesn't exist unless it's logged. As a computer programmer himself, Oakley ought to know better, because a log message occurs only if the programmer specifically, intentionally writes a logging statement in the program. Not everything that happens on your Mac is magically logged.
Here's Oakley's own theory about the slow launches:
The most likely activity to account for these long checking times is computation of SHA-256 hashes for the contents of each item in the app’s Frameworks folder. Thus, these occasional extremely long launch times are most probably due to time taken ‘evaluating trust’ by computing hashes for protected code in the Frameworks folder in the app bundle, when those hashes have been flushed from their cache.
Oakley seems to be claiming, with no empirical evidence, that Macs have a cache of SHA-256 hashes of all bundled files of all apps that have been launched. But where exactly is this cache??? I've never seen it or heard of such a thing. As far as I can tell, it's pure speculation by Oakley based on nothing but a terse log message:
com.apple.syspolicy.exec Recording cache miss for <private>Ironically, the references to com.apple.syspolicy.exec and AppleSystemPolicy in his log messages appear to match quite well with the results of my spindumps. I don't deny that something is cached, but I think the evidence suggests that what is cached is the result of a malware scan, which for practical purposes would make a lot more sense than a bunch of hashes. After all, malware definitions are periodically updated for newly discovered malware, which means that the results of previous malware scans would eventually become outdated. Whereas Oakley's theory doesn't make much sense to me. The code signature of executables is always checked when the executable is loaded at runtime, so if the app has been modified since the previous launch, that would be detected anyway. Moreover, apps have some protections against modification: App Store apps are owned by the root user, and the App Management feature prevents (or is supposed to prevent) notarized apps from unauthorized modification. Thus, I don't even understand the utility of caching SHA-256 hashes of bundled files and periodically recalculating them.
It's also worth noting that Oakley's discussion of hashing performance ignores a key detail: the apps that he examines are universal binaries, with both Intel and ARM architectures. This doubles the size of the bundled dynamic libraries. Oakley runs some hashing tests based purely on the sizes of files, but as Apple explains in a tech note linked to by Oakley's article, each architecture has its own separate code signature:
The command above includes the--arch x86_64option to show the Intel code signature. Without thatcodesignshows the code signature for the architecture on which you run the command. So, if you’re on Apple silicon, you’ll see the Apple silicon code signature.
When an app is launched, it's unlikely that the system would inefficiently spend time checking the code signature of an unused architecture, so whatever checks are performed should be measured against only the half of the sizes of the executables.
Overall, as far as I can tell, there's nothing new here, and Oakley is simply observing the same phenomenon that I already observed last year.