Many of you noticed that, following last Thursday’s update to XProtect Remediator (XPR), there were one or two warnings noted in SilentKnight and XProCheck. My own records showed this too, with:
2023-02-02 23:58:19.144 MRTv3 ⚠️{"caused_by":[],"status_message":"Unknown","status_code":31,"execution_duration":0.00016105175018310547}
2023-02-03 00:01:48.971 Genieo ⚠️{"caused_by":[],"status_message":"Unknown","status_code":31,"execution_duration":0.00013697147369384766}
If you looked again once XPR had run another set of scans, you’ll have noticed they’ve since returned to normal. This article explores how and why.

What happened in the log

If you were to look in the log around the times of those warnings, you might be even more puzzled. The first of those, occurring at 2023-02-02 23:58:19, contained the following notable entries.

Both appeared to come out of the blue, when XProtectPluginService had just started one of its periodic scans:
19.143590 com.apple.XProtectFramework.Plugin XProtectRemediatorMRTv3 PluginService has an invalid code signature, terminating

This resulted in the log entry you see in XProCheck:
19.144380 com.apple.XProtectFramework.PluginAPI XProtectRemediatorMRTv3 {"caused_by":[],"status_message":"Unknown","status_code":31,"execution_duration":0.00016105175018310547}
which gives nothing away. So how come a freshly updated copy of XPR had an invalid code signature? Could it have been malicious, or was that update broken?

Following log entries then show what happened. First, the offending scanner module inside XPR was exited, and its XPC communications with other processes, in particular XProtectPluginService, were cancelled.
19.144390 XProtectRemediatorMRTv3 CoreAnalytics Entering exit handler.
19.144416 XProtectRemediatorMRTv3 CoreAnalytics Cancelling XPC connection. Any further reply handler invocations will not retry messages
19.144446 XProtectRemediatorMRTv3 CoreAnalytics XPC connection invalidated (daemon unloaded/disabled)
19.274219+0000 Error XProtectPluginService com.apple.XProtectFramework.plugins.MRTv3 @ file:///Library/Apple/System/Library/CoreServices/XProtect.app/Contents/MacOS/XProtectRemediatorMRTv3 - BB9B968A-D632-49BC-9CC4-2F1A2363DB47 exited with .badPluginServiceSignature - exiting

This was propagated to XProtectPluginService, which runs these scans.
19.274224 XProtectPluginService CoreAnalytics Entering exit handler.
19.274267 XProtectPluginService CoreAnalytics Cancelling XPC connection. Any further reply handler invocations will not retry messages
19.274305 XProtectPluginService CoreAnalytics XPC connection invalidated (daemon unloaded/disabled)
19.274346 Error [XPC Server] managed connection recieved connection invalidated: Connection invalid
19.274523 Fault com.apple.XProtectFramework XProtect XPC connection interrupted
19.275667 system/com.apple.XprotectFramework.PluginService [1946] launchd launchd exited due to exit(0)
19.275694 system/com.apple.XprotectFramework.PluginService [1946] launchd launchd service state: not running
19.275699 pid/1946 [XProtectPluginS] launchd launchd shutting down
19.275708 launchd removing child: pid/1946
In the last two of those entries, that process ID (PID) is that of XProtectPluginService.

Then the underlying cause is revealed, and that attempt at a scan abandoned as complete.
19.278403 Fault XProtectPluginService connection error: Couldn’t communicate with a helper application.
19.278445 com.apple.XProtectFramework XProtect Finished system scan, ran as 0
19.278491 Fault com.apple.XProtectFramework XProtect XPC connection invalidated
19.278543 Completed XPC Activity: com.apple.XProtect.PluginService.daemon.scan (0x7fd016514e60)

As this is a periodic task, its next set of scans was set up with Duet Activity Scheduler (DAS), to run in 24 hours time.
19.282677 com.apple.duetactivityscheduler Submitted Activity: 0:com.apple.XProtect.PluginService.daemon.scan:15EF08 at priority 30 with interval 86400 (Fri Feb 3 23:54:02 2023 - Sat Feb 4 23:54:02 2023)

This occurred twice: once for the scan run as root (above), and once for that run as the current user, at 2023-02-03 00:01:48.971, generating the second warning message. Look for XProtectPluginService in Activity Monitor and you’ll see two processes, one owned by the current user and the other by root. These are background services set up by property lists in /Library/Apple/System/Library/LaunchAgents and LaunchDaemons, and left running all the time so they can periodically call off XPR scans by XPR’s plugins.

What should have happened

For macOS to update XPR, what should happen is that the current running XProtectPluginService processes for both the user and root are stopped, the update installed, and XProtectPluginService started up again and added to DAS for scanning using the new version of XPR later. That’s why, after each XPR update, its scan schedule is reset, and likely to be run at a different time of day. In this update, it appears that corners were cut, which led to the problem.

What went wrong

XProtectPluginService is one of over 300 background services scheduled and dispatched by DAS-CTS. It communicates with the scanning modules using XPC. It has long been recognised that those communications could be vulnerable, allowing malicious software to hijack them. Imagine if you could replace one of XPR’s scanning modules with something that did the opposite, and maybe sent the contents of your keychain to a remote server. So it has become essential that XPC connections are secure, thus verifiable by signature. This has just been enhanced in Ventura, which now gives third-party developers access to signature-based checks in NSXPCConnection.

In this case, the previous XProtectPluginService was left running after the update had been installed. The next time that it tried to run a set of scans, it and the new scanning modules couldn’t agree on the signature expected to be used to secure their XPC connection. As a result, the scanning module was exited, followed by XProtectPluginService. As the latter is an expected service, when it was reinstated, it was running the newly installed version. When that was used to run the next scans, the signatures were all properly aligned, and no more errors occurred.

That’s true of Macs which are left running all the time. If you shut down or restarted your Mac in the period between the update being installed, and the next scheduled time to run XPR scans, then you wouldn’t have seen any errors or warnings, because the next scans would be performed completely with the new version of XPR, including XProtectPluginService.

Reporting

So why didn’t the report by XProtectFramework’s PluginAPI explain what the problem was, instead of giving “caused_by” as [], and “status_message” as "Unknown"? Probably because this isn’t intended to be its public interface, and users aren’t supposed to know gory details of internal matters. That seems like another vote in favour of log literacy.