LoginLast Week on My Mac: Checking code can take longer now
Many of you have commented that you too find that apps and command tools can now take surprisingly long to launch. Although my previous analyses have demonstrated how those can often be attributed to security checks being made on components including frameworks and dylibs, there remains some dispute over the nature of those checks. Although I believe there’s convincing evidence that those checks are prolonged to recompute hashes and CDHashes, others are adamant that they are in fact ‘malware scans’. This article considers new evidence.
Inspecting and analysing the log during the launch of large apps isn’t the best way of getting a clear view of what happens when macOS runs its security checks. There’s a great deal going on at the time, with multiple security checks being performed for TCC, LaunchServices and RunningBoard in dialog, sandboxes and containers to set up, and iCloud services to connect. Last week I’ve been tackling this more methodically, and here use two launches of a simple command tool to give clearer insights into what’s going on when macOS runs its security checks.
Methods
The command tool in question is my blowhole, just over 200 KB of simple code to write a message to the log, hence directly telling us when it’s run. It has its signing certificate embedded into its Mach-O binary, and is notarized. However, because it’s a single binary and not an app bundle, its notarization ticket is stapled to its installer package, and not to the tool itself.
The two runs I analyse here are:
- On a Mac Studio M1 Max running macOS Ventura 13.4.1 at 14:32 on 4 July 2023.
blowholehad already been installed on that Mac, but the copy being run was in a previously unknown location, ~/Documents, which normally forces macOS to perform more extensive security checks, including an XProtect scan and notarization checks, but not as thorough as when in quarantine. - On a Mac mini M4 Pro running macOS Sequoia 15.4.1 at 20:07 on 2 May 2025. Although
blowholehad been installed and run some weeks previously, it hadn’t been run since then, and was expected to attract more extensive security checks, including an XProtect scan and notarization checks, but not as thorough as when in quarantine.
The first of those was collected using Ulbow, and the second by LogUI. Excerpts giving milestone entries are given in the Appendix at the end. In the diagrams below, each milestone is given with time in seconds elapsed since the first mention of the binary.
Ventura
First mention of the tool to be run comes from AppleMobileFileIntegrity (AMFI), which leads immediately to its daemon amfid starting its assessment of the binary, with the entry SecTrustEvaluateIfNecessary to inspect the signature and the CDHashes it contains. As this takes a mere 0.003 seconds, and the next stage starts 0.01 seconds after amfid entered the path to the binary, all that could have done was confirm the integrity of the signature, its requirements, and that its hashes were already cached.
syspolicyd then records the start of the Gatekeeper process assessment, and initiates the Gatekeeper scan, first starting checks on the notarization ticket, then starting the XProtect scan while ticket checking proceeds. Of those, the XProtect scan completes first, returning its results to syspolicyd at 0.054 seconds after the start.
Ticket checking involves an explicit connection to iCloud using CloudKit, with abundant log entries. The CloudKit Ticket Store is found to be reachable, and the ticket checked for the CDHashes obtained earlier from the tool’s signature.
With both checks completed satisfactorily, at 0.192 seconds the Gatekeeper scan is declared complete, syspolicyd evaluates its result, and is almost ready for the tool to run. Before that can happen, details of the executable are entered into provenance tracking. syspolicyd confirms the evaluation allows the tool to run, and AppleSystemPolicy records the evaluation result.
Sequoia
The sequence here is very similar to that in Ventura, with some significant differences, marked in the emphasised items in the diagram above.
First, there’s a substantial delay of 0.063 seconds between amfid entering the binary’s path and the start of the Gatekeeper process assessment. This started with entries from amfid recording SecTrustEvaluateIfNecessary and trustd SecKeyVerifySignature, indicating that more took place here than in Ventura. However, there’s no evidence of any external signature checks being made, and it’s most likely that the binary’s hashes weren’t cached, so required recomputation to verify them. The delay is woefully inadequate for any form of malware scan to have taken place at this stage.
When XprotectService reports that XProtect is performing the malware scan, it additionally reports the location of the XProtect rules being used. That’s because Sequoia introduced a new location used for those data files, in /var/protected/xprotect/XProtect.bundle/Contents/Resources/XProtect.yara as recorded here.
Next, the XProtect scan here takes 0.126 seconds, rather than 0.030 seconds in Ventura. This is the result of the huge growth in the number and complexity of the Yara rules used for this scan over the last two years. The Ventura scan was performed using version 2168 of those rules, with a Yara file of 147 KB size and around 218 rules. By version 5296 used in the Sequoia scan, file size had risen to 947 KB with about 381 rules.
Size of the binary being scanned also affects scan time, although in an unexpected way. A great many of the Yara rules used include upper limits to file size, so those larger than a few MB are subject to few rules, probably intentionally. Thus, larger binary files are likely to complete their XProtect scan in shorter time than expected, and maybe more quickly than smaller binaries.
As a result of these two delays, Gatekeeper’s XProtect results aren’t reported until 0.247 seconds have elapsed since the start, already over 0.05 seconds longer than the whole process in Ventura. However, in this case there’s no mention of provenance tracking, and the blowhole tool is finally run after 0.3 seconds, taking just over 150% of the time in Ventura.
Summary of security checks
- Trust evaluation and signature verification, to confirm hashes and CDHashes if not cached;
- Gatekeeper scan, including simultaneous ticket check and XProtect malware scan;
- CDHash ticket check online using CloudKit with iCloud Ticket Store;
- XProtect malware scan against Yara rules;
- Gatekeeper evaluation for
syspolicydto allow or not; - Result registered with the kernel;
- Command tool run.
Note that there’s no evidence of any OCSP checks being made with the certificate authority to determine whether certificates have been revoked. Additional time will be required if hashes and CDHashes are to be recomputed, and as a result of increased Yara rules.
Appendix: Log Milestones
Times are given in seconds, adjusted to a start of 0.0. The Ventura extract was obtained with log privacy disabled.
Ventura 13.4.1 2023-07-04 14:32:40 on Mac Studio M1 Max
XProtect version 2168, Yara file 147 KB, 218 rules0.000000 AppleMobileFileIntegrity Checking in with amfid for DER co.eclecticlight.blowhole
0.001395 amfid Entering OSX path for /Users/howardoakley/Documents/blowhole
0.010608 syspolicyd GK process assessment: /Users/howardoakley/Documents/blowhole <-- (/bin/zsh, /System/Applications/Utilities/Terminal.app/Contents/MacOS/Terminal)
0.022891 syspolicyd GK performScan: PST: (path: /Users/howardoakley/Documents/blowhole), (team: (null)), (id: (null)), (bundle_id: (null))
0.023291 syspolicyd looking up ticket: {length = 20, bytes = 0xe0cad936293cea0807ec2e5193bed5f3f02dc019}, 2, 1
0.023316 syspolicyd cloudkit record fetch: https://api.apple-cloudkit.com/database/1/com.apple.gk.ticket-delivery/production/public/records/lookup, 2/2/e0cad936293cea0807ec2e5193bed5f3f02dc019
0.023554 XprotectService Xprotect is performing a direct malware and dylib scan: /Users/howardoakley/Documents/blowhole
0.053971 syspolicyd GK Xprotect results: PST: (path: /Users/howardoakley/Documents/blowhole), (team: (null)), (id: (null)), (bundle_id: (null)), {
XProtectMalwareType = 0;
XProtectSignatureVersion = 4321574501753746074;
}, version: 4321574501753746074
0.170283 syspolicyd CKTicketStore network reachability: 1, Wed Jun 21 19:33:35 2023
0.191576 syspolicyd GK scan complete: PST: (path: /Users/howardoakley/Documents/blowhole), (team: (null)), (id: (null)), (bundle_id: (null)), 4, 4, 0
0.191797 syspolicyd GK evaluateScanResult: 2, PST: (path: /Users/howardoakley/Documents/blowhole), (team: QWY4LRW926), (id: co.eclecticlight.blowhole), (bundle_id: NOT_A_BUNDLE), 0, 0, 1, 0, 4, 4, 0
0.191996 syspolicyd Putting executable into provenance with metadata: TA(917fa0aed8a1a838, 0)
0.191999 syspolicyd Putting process into provenance tracking with metadata: 1410, TA(917fa0aed8a1a838, 0)
0.192054 syspolicyd GK eval - was allowed: 1, show prompt: 0
0.192090 AppleSystemPolicy evaluation result: 17, allowed, cache, 1688477560
0.195467 blowhole Blowhole snorted!
Sequoia 15.4.1 2025-05-02 20:07:00 on Mac mini M4 Pro
XProtect version 5296, Yara file 947 KB, 381 rules0.000 amfid Entering OSX path for /usr/local/bin/blowhole
0.063 syspolicyd GK process assessment: <private> <-- (<private>, <private>)
0.081 syspolicyd GK performScan: PST: (path: cc151acaee5bc8cd), (team: (null)), (id: (null)), (bundle_id: (null))
0.082 syspolicyd looking up ticket: <private>, 2, 1
0.082 syspolicyd cloudkit record fetch: <private>, <private>
0.121 XprotectService Xprotect is performing a direct malware and dylib scan: <private>
0.125 XprotectService Using XProtect rules location: /var/protected/xprotect/XProtect.bundle/Contents/Resources/XProtect.yara
0.247 syspolicyd GK Xprotect results: PST: (path: cc151acaee5bc8cd), (team: (null)), (id: (null)), (bundle_id: (null)), XPScan: 0,1089725382763820427,2025-05-02 19:07:00 +0000,(null),(null),file:///usr/local/bin/blowhole
0.283 syspolicyd CKTicketStore network reachability: 1, Fri May 2 17:21:52 2025
0.293 syspolicyd GK scan complete: PST: (path: cc151acaee5bc8cd), (team: (null)), (id: (null)), (bundle_id: (null)), 4, 4, 0
0.295 syspolicyd GK evaluateScanResult: 2, PST: (path: cc151acaee5bc8cd), (team: QWY4LRW926), (id: co.eclecticlight.blowhole), (bundle_id: NOT_A_BUNDLE), 0, 0, 1, 0, 4, 4, 0
0.296 syspolicyd GK eval - was allowed: 1, show prompt: 0
0.296 kernel evaluation result: 5, exec, allowed, cache, 1746212820, 4, 4, f1f7b76465d358b, 1746212820, /usr/local/bin/blowhole
0.303 blowhole Blowhole snorted!
For comparison, Catalina’s log entries are remarkably similar too.
