In a couple of months’ time, we should be discovering what has changed in macOS 10.14 Mojave. Before that, I thought it might be helpful to establish what happens in High Sierra (and, to a greater extent, in Sierra too) when you open an app, in particular one which bears the quarantine extended attribute, so that it goes through a full Gatekeeper check and app translocation.

When a ‘normal’ app opens, provided that it has no quarantine flag, it only undergoes a quick check to ensure that it matches its signing information, so hasn’t been tampered with in any way. This is normally marked by a short series of log entries in which the certificate is checked against the contents:
0.345282 trustd cert[2]: AnchorTrusted =(leaf)[force]> 0
0.346411 Security MacOS error: -67050
0.346449 Security MacOS error: -67050
0.349173 Security SecTrustEvaluateIfNecessary
0.350490 trustd cert[2]: AnchorTrusted =(leaf)[force]> 0
0.351656 Security MacOS error: -67050
0.351704 Security MacOS error: -67050
and so on. Throughout these log excerpts, the time shown for each entry is in seconds, from a start which is actually slightly after zero.

Then Launch Services gets going with the app, and there are long and irrelevant exchanges until it actually launches the app, in this case SystHist:
0.642147 LaunchServices LaunchApplication: appToLaunch={ "ApplicationType"="Foreground", "CFBundleExecutablePath"="/Applications/SystHist.app/Contents/MacOS/SystHist", "CFBundleExecutablePathDeviceID"=16777220, "CFBundleExecutablePathINode"=6462051, "CFBundleIdentifier"="co.eclecticlight.SystHist", "CFBundleName"="SystHist", "CFBundlePackageType"="APPL", "LSBundlePath"="/Applications/SystHist.app", "LSBundlePathDeviceID"=16777220, "LSBundlePathINode"=6462046, "LSExecutableFormat"="LSExecutableMachOFormat", "LSLaunchDLabel"="co.eclecticlight.SystHist.44144" } modifiers: { "AddPSNArgument"=true, "LSAdditionalEnvironmentVars"={ }, "LSLaunchAsync"=true, "LSLaunchStoppedTemporarily"=true } args=[ NULL ]

There follow many more entries until Launch Services confirms it is opening the app:
0.647900 LaunchServices LaunchedApplication: "/Applications/SystHist.app/Contents/MacOS/SystHist", psn=[ 0x0/0x4e04e]
This is an entry worth noting: if you want to find launched apps in the logs, filter traffic for the com.apple.launchservices subsystem, looking for the string “LaunchedApplication:” in the eventMessage field, and you should see a fairly complete list (in High Sierra).

Finally, the app actually appears, loads its preferences, and checks in with Launch Services:
0.668338 SystHist CoreFoundation Loading Preferences From System CFPrefsD For Search List
0.668514 SystHist CoreFoundation Loading Preferences From User CFPrefsD For Search List
0.674291 SystHist LaunchServices LSApplicationCheckIn(), app being registered is:"/Applications/SystHist.app/Contents/MacOS/SystHist"

In Sierra and later, a different course is followed when first launching any app with the quarantine extended attribute set. My example here is Cirrus, rather than SystHist, and times are again given in seconds.

The initial security check is immediately changed into the more extensive Gatekeeper check, although interestingly the word Gatekeeper doesn’t appear anywhere in the log:
0.563279 Security SecTrustEvaluateIfNecessary
0.564686 trustd cert[2]: AnchorTrusted =(leaf)[force]> 0
0.566865 LaunchServices Parsed Info.plist for <private>
0.566883 LaunchServices Parsed MobileInstallation data for <private>
0.571040 Security SecTranslocateCreateSecureDirectoryForURL: created /private/var/folders/dc/p5l3qqtn5wbb_snq36008jzc0000gn/T/AppTranslocation/C4A1F2B7-DFEB-414E-8616-93B74D55868D/d/Cirrus.app

That last entry marks the translocation step: with the quarantine flag set, the app is moved to a temporary folder in /private/var/folders to be run from there, a step which was introduced in Sierra.

Launch Services now starts an extended process to cope with the Gatekeeper checks and translocation:
0.580223 LaunchServices LaunchApplication: appToLaunch={ "ApplicationType"="Foreground", "CFBundleExecutablePath"="/private/var/folders/dc/p5l3qqtn5wbb_snq36008jzc0000gn/T/AppTranslocation/C4A1F2B7-DFEB-414E-8616-93B74D55868D/d/Cirrus.app/Contents/MacOS/Cirrus", "CFBundleExecutablePathDeviceID"=771751939, "CFBundleExecutablePathINode"=6470977, "CFBundleIdentifier"="co.eclecticlight.CirrusMac", "CFBundleName"="Cirrus", "CFBundlePackageType"="APPL", "LSApplicationLockedInStoppedStateKey"=true, "LSBundlePath"="/private/var/folders/dc/p5l3qqtn5wbb_snq36008jzc0000gn/T/AppTranslocation/C4A1F2B7-DFEB-414E-8616-93B74D55868D/d/Cirrus.app", "LSBundlePathDeviceID"=771751939, "LSBundlePathINode"=6470972, "LSExecutableFormat"="LSExecutableMachOFormat", "LSLaunchBeforeTranslocationExecutablePathDeviceID"=16777220, "LSLaunchBeforeTranslocationExecutablePathINode"=6470977, "LSLaunchBeforeTranslocationLaunchBundlePathDeviceIDKey"=16777220, "LSLaunchBeforeTranslocationLaunchBundlePathINodeKey"=6470972, "LSLaunchBeforeTranslocationLaunchBundlePathKey"="/Users/hoakley/Other<…> modifiers: <decode: missing data> args=<decode: missing data>

After many more log entries, when LaunchServices finally announces that is has launched the app, it cites the translocation path:
0.598152 LaunchServices LaunchedApplication: "/private/var/folders/dc/p5l3qqtn5wbb_snq36008jzc0000gn/T/AppTranslocation/C4A1F2B7-DFEB-414E-8616-93B74D55868D/d/Cirrus.app/Contents/MacOS/Cirrus", psn=[ 0x0/0x43043]
and this is only the start of an extended launch sequence – the app isn’t actually running yet, not by a long way.

Sequences of security entries often contain error codes. In this case, 8 is uninformative, but -67050 means that the code failed to satisfy one of the code requirements, and is one of the more common security errors seen during ‘normal’ operations:
0.601824 Security UNIX error exception: 8
0.603917 Security SecTrustEvaluateIfNecessary
0.603987 Security SecTrustEvaluateIfNecessary
0.605412 trustd cert[2]: AnchorTrusted =(leaf)[force]> 0
0.605766 trustd cert[2]: AnchorTrusted =(leaf)[force]> 0
0.607856 Security MacOS error: -67050
0.608035 Security UNIX error exception: 8
0.608251 Security SecItemCopyMatching
0.608257 Security SecItemCopyMatching_ios
0.609525 LaunchServices Opening trusted signature database at <private>

At the end of that sequence, the local trusted signature database, presumably what we refer to as Gatekeeper’s data files, are opened.

Until now, there has been no reference to Gatekeeper or XProtect, but over the next period, XProtect appears in a sequence of log entries:
0.642167 XprotectService libsystem_info.dylib Retrieve User by ID
0.664920 XprotectService libsystem_info.dylib Membership API: translate identifier
0.670323 XprotectService CoreFoundation Loading Preferences From System CFPrefsD For Search List
0.670594 XprotectService CoreFoundation Loading Preferences From User CFPrefsD For Search List
0.681322 XprotectService Security SecKeychainAddCallback
0.697749 XprotectService Security MacOS error: -67050
0.697821 XprotectService Security MacOS error: -67050
0.697901 XprotectService Bundle is not apple signed
0.699033 XprotectService Bundle size result: 17625311 (YES)
0.699034 XprotectService Always scan: YES
Note error -67050 again, and the check to see whether the app bundle has been signed using an Apple certificate.

Eventually, XProtect comes back with a result, which is kindly censored by the unified log’s privacy mechanism. Note that more than 0.5 second has now elapsed since these security checks started:
1.223427 XprotectService SecAssessment results: <private> (null)
1.225236 XprotectService Security SecTrustEvaluateIfNecessary
1.226320 trustd cert[2]: AnchorTrusted =(leaf)[force]> 0
1.331717 XprotectService Starting malware scan for: <private>

Only now does XProtect start scanning the app for malware. Once that is complete (buried in the torrent of other log entries), and all the checks have been passed, macOS displays the dialog inviting the user to open the app, which results in a further delay while the user responds. Once they do, the quarantine extended attributes are stripped from all the component items within the app bundle, which can of course result in errors if they are not present:
3.441475 CoreServicesUIAgent error -1 while removing quarantine data on path /Users/hoakley/OtherDocuments/Cirrus.app/Contents/Frameworks/libswiftObjectiveC.dylib

Recall here that extended attributes are excluded from signatures, so removing those xattrs does not invalidate any signature. They are also stripped not from the translocated copy of the app, but from the original.

Eventually, the app launches and similar log entries mark its getting going:
3.593421 Cirrus libsystem_info.dylib Retrieve User by ID
3.594023 Cirrus CoreFoundation Loading Preferences From System CFPrefsD For Search List
3.594388 Cirrus CoreFoundation Loading Preferences From User CFPrefsD For Search List
3.600877 LaunchServices LSApplicationCheckIn(), app being registered is:"/private/var/folders/dc/p5l3qqtn5wbb_snq36008jzc0000gn/T/AppTranslocation/C4A1F2B7-DFEB-414E-8616-93B74D55868D/d/Cirrus.app/Contents/MacOS/Cirrus"

Finally, recall that this is being run from its translocation folder still, as Launch Services points out.

I will revisit these log sequences in the autumn/fall, when we know how they are altered in Mojave, and how its new notarization system affects it.