DDM Software Update Logs
To learn more about prompted (or unprompted) DDM software update restarts, we took a look at the important, but temperamental, /var/loginstall.log.
Users experiencing DDM software updates in Sonoma for the first time may be encountering the new macOS update deadline feature. Trouble is, that some unprepared users may complain about what they perceive to be forced or unprompted restarts. To stay ahead of this, let's take a dive to see what we could learn about these forced restarts and if they truly were unprompted.
Grain of salt with this one, folks. While we had a nice, tidy file to look into regarding the current DDM SWU status of a Mac, I haven't found an elegant way to pull this information. So, for the time being, we're getting our hands dirty and digging into everyone's favorite morass, /var/log/install.log.
This file can be enormous on many devices - dozens of megabytes of plaintext. It also automatically truncates now and then, so referencing it can be helpful for recent activity, but I wouldn't recommend relying on it for historical information. With that limitation in mind, let's see what we can learn about DDM software updates inside of that log.
DDM Software Update Notification Center notifications
To begin the search, I opened the log file in Console and ran a search for "DDM", to see what I could find. After some poking around, I was able to find something that looked promising:
2023-11-07 19:44:39-05 testdevice softwareupdated[455]: -[SUOSUManagedServiceDaemon scheduleEnforcedManagedUpdateWithVersion:forDate:withOptions:completion:]_block_invoke: Posted DDM notification with success: YESSample DDM line from /var/log/install.log
Over the coming weeks, as additional updates eventually came out (or in test VMs), I tried to see if this line would pop out roughly when Notification Center notifications would appear for users. It seemed... mostly accurate. At least a place to begin. So, here's a one-liner you can run to look for these successful notification logs:
grep "SUOSUManagedServiceDaemon: Posted DDM notification with success: YES" /var/log/install.log | awk '{print $1, $2}'
# EXAMPLE OUTPUT:
# 2024-01-07 21:34:16-06
# 2024-01-07 21:39:36-06
# 2024-01-07 21:48:45-06
# 2024-01-07 21:56:36-06
# 2024-01-07 22:03:52-06
# 2024-01-07 22:12:34-06
# 2024-01-23 05:51:45-06One-liner to get a list of successful user-facing DDM notifications with sample output
I ran this on a few machines and saw consistent results - the pings started off about daily and then grew in frequency leading up to the expiration date. This was a great tool to show someone "Here are all the times your Mac tried to tell you that your updates were due soon, and you had all this time to just restart and do it". In the above example output, you can see the cluster of notifications leading up to the application of a previous patch, then a brand new one for the next available point update.
DDM Software Update Forced Restart History
Back to the log mines. Thankfully, when someone complains about a forced restart, they're usually complaining because it happened right before a meeting. While unfortunate, that often means they can give us a pretty good idea as to when it occurred so we have a place to begin our research.
Combing through the logs, there were plenty of breadcrumbs to follow - here are some of the interesting lines I ran into along the way:
2023-11-07 16:28:43-05 testMac softwareupdated[455]: MSU updates have changed since last scan, update policy to default
Example log line indicating a DDM SWU scan is needed
2023-11-07 16:29:06-05 testMac softwareupdate[63525]: Controller: Received startup notification; new updates: [MSU_UPDATE_23B81_patch_14.1.1_minor]; new major updates: []
Example log line indicating a new update was found
2023-11-07 16:34:27-05 testMac SoftwareUpdateNotificationManager[1774]: SUOSUShimController: MSU update is not yet downloaded & prepared: <SUOSUProduct: MSU_UPDATE_23B81_patch_14.1.1_minor>Example log line indicating a download is required
2023-11-10 16:05:01-05 testMac softwareupdated[455]: SUOSUManagedServiceDaemon: Use standard 24 hour DDM notification interval
Example log line indicating a notification cadence is being set
2023-11-14 08:27:12-05 testMac softwareupdated[455]: SUOSUManagedServiceDaemon: Within 30 min of enforced update, updating notification frequency to every 10 minutesExample log line indicating a DDM SWU is staged and the notification frequency is changing
2023-11-14 09:27:15-05 testMac SoftwareUpdateNotificationManager[1774]: Restarting for software update (forced=1)And here it is - a forced DDM Software Update restart
Finally, we found the line to look for indicating that the Software Update service was triggering a forced restart. Converting this to a one-liner:
grep "forced=1" /var/log/install.log | awk '{print $1, $2}'
# Example output: 2023-11-14 00:00:04-06One-liner to output a list of recent forced DDM software update restarts
As the DDM spec continues to evolve, and with each new version of macOS, there's a chance this syntax will change. So, tread carefully here, and I hope these commands can be helpful for the time being. If you want to track this longitudinally and avoid the trouble with the install.log file auto-truncating, I may recommend running these commands as recurring daily/weekly maintenance items and outputting their results into a separate log (only importing new lines not detected in your semi-permanent log file).