Hunting malware protection in the log

Several readers have asked me how they can check that the new anti-malware protection in macOS, XProtect Remediator, is active and scanning on their Macs. Given that scans are most likely to be run when you’re not active on your Mac, possibly when you’re still asleep, and the longest takes less than a minute, the chances of catching a scan in Activity Monitor are slim indeed. As far as I can tell, the best place to look is in the Unified log. This article first explains how I worked out how to find these scans, then explains how you can.

Hunting

I’ve been looking at this new anti-malware feature for the last three months, since I stumbled across its introduction in macOS 12.3 back in March. It superficially looked like a new app named XProtect.app, in the part of CoreServices stored on the Data volume and firmlinked to that folder on the System volume. As it contains an XPC service named XProtectPluginService, I looked in the accompanying property lists in LaunchAgents and LaunchDaemons. Sure enough, they refer to an XPC activity named com.apple.XProtect.PluginService.agent.fast.scan.

My first log searches drew a blank, as I tried various shortenings of that name as subsystems. I then tried looking for XProtect in the message field, and discovered DAS-CTS activity which was trying to dispatch XProtectFramework processes. Careful search of full log extracts enabled me to find the moment that a scan was launched, from which I arrived at a subsystem of com.apple.XProtectFramework.PluginAPI.

Once I knew the subsystem to use in a search predicate, I looked back in steadily increasing periods of time until I was checking windows of an hour. After some complete blanks, I struck gold at a log time of around 0600, shortly before I normally get up.

Finding

To reassure yourself that your Mac running Catalina or later is performing these scans, you’ll need a copy of my free log browser Ulbow, and be logged in as an admin user; if you are adept at using the log show command in Terminal, feel free to use that instead. The latter is because Ulbow uses the log show command to obtain its log contents, and those are only accessible to admin users. (Yes, I know that Ulbow could use a privileged helper app to avoid this, but I’m still negotiating the complexities of implementing that.)

Once you’ve moved Ulbow into an Applications folder so it doesn’t get run in translocation (which can do weird things), open the app. Copy the following text to use as the search predicate, and paste it into the Predicate box:
subsystem == "com.apple.XProtectFramework.PluginAPI"

Be careful that you only paste one copy, and that the double-quotation marks are standard vertical ones, not typographic quotes.

remed01

Set the style to starters+, my favourite, and click on the Now button to set the clock time to that moment. Our first search is going to cover the last full hour, so set the Period to 1 hour, then select the hour and step it back two hours, and the minutes and seconds both to zero.

remed02

If you’re lucky, clicking on the Get log button will find you some log entries from an XProtect Remediator scan. However, as we’re looking for needles in a haystack, be ready to check the previous hour. To do that, select the hour in the clock and step it back by one before clicking Get log again. Keep repeating this until you find an hour with some scan entries. If necessary you can wind this back a day or two, or increase the Period used.

remed03

Here, shown in red and green, is one of many from a scan for DubRobber.

Refining

The snag with this particular search predicate is that it not only finds the results of each scan, but also shows their errors and other entries. Now’s the time to use a more specific predicate to reveal just those log entries giving scan results. Look carefully in a log extract and you’ll notice those all come with the text XPEvent.structured shown in black.

In the starters+ style, those entries in black come from the category field of the log entry. You can check that by opening Ulbow’s Preferences and selecting starters+ from the styles there: the formatting string runs
0 2g 6 9 4b 3 11fr 13fg 10
The subsystem field is formatted as 4b, as it is field 4 and coloured blue. A key to the fields and their numbers is given in the Field Help window, in the Help menu. The field shown in plain black after the subsystem is number 3, which is the category. So what we want to add to the existing search predicate is to AND with category == "XPEvent.structured", which makes the whole predicate
subsystem == "com.apple.XProtectFramework.PluginAPI" && category == "XPEvent.structured"

remed04

Because there will only be a few dozen log entries each day which satisfy that predicate, we can increase the period to several days if we wish. Here’s my Mac’s golden hour after 1000, when I was out enjoying a walk in the sunshine.

remed05

It’s good to see that my Mac wasn’t wasting its time while I was away.

For those who prefer an easier way, Mints version 1.9 will be available later tonight (GMT), and announced formally on Friday morning. It contains a new button to check for XProtect Remediator scans, using the refined predicate above.