A brief history of logs and Console

0

System logs seem to have been introduced with Mac OS X in 2000-2001, and I don’t recall any equivalent in Classic Mac OS, although individual apps such as databases often kept their own logs.

2000-2016 text logs

As Mac OS X presented itself as a derivative of Unix, it brought with it bells and whistles such as support for code to write to system-level logs including system.log, console.log and dozens of other more specialist destinations, and its own log browser in the Console app.

As is traditional, log entries contained unstructured plain text to which a datestamp and other data were added to expand each into a line of text in log files that were rotated daily. As entries were relatively infrequent, many users learned to read the log and to use it to diagnose problems.

The Console app gave ready access to all standard logs as well as app-specific ones, such as this for mail processes such as sendmail, and crash reports. These two screenshots are from Mac OS X 10.0 Cheetah in April 2001.

By Mac OS X 10.4 Tiger in 2005, Console had acquired some basic tools and a sidebar to select from the many logs. Because they were plain text, those for previous days were compressed and stored in archives until they were removed during routine housekeeping. This excerpt shows entries in the system log over a restart that took over 2 minutes from the last entry to the start of the boot process.

There has also been the rare substitute for Console: this is LogMaster from Bright Light Software, shareware for $14.50 in 2006 until it was abandoned.

Although much in Console remained the same until 2016, at some stage Apple structured log entries into fields, as shown here in Mac OS X 10.6 Snow Leopard. Log entries were still infrequent, with this excerpt covering a period of almost 20 seconds.

This is another restart, here in OS X 10.10 Yosemite in April 2015. This time, the period recorded for that restart has fallen to 39 seconds. System shutdown is marked by the shutdown process and SHUTDOWN_TIME, and startup begins with BOOT_TIME.

2016 Unified log

With macOS Sierra in 2016, that was all swept away and replaced by the Unified log. There had been warning signs that change was coming: in May of that year, I complained that the log consisted of a torrent of messages like
17/05/2016 21:04:40.175 storeassetd[531]: multibyte ASN1 identifiers are not supported.
or
17/05/2016 20:55:15.298 WindowServer[233]: _CGXRemoveWindowFromWindowMovementGroup: window 0x91 is not attached to window 0x92
Even when running a fairly clean installation of El Capitan, All Messages clocked up around 4000 entries every 8 or 9 hours. At its worst, the log could fill those 4000 message slots in a minute or two. Little did we realise how busy our logs were about to become.

Apple declared the goals of its new log system at WWDC in June 2016:

a single efficient logging mechanism for user and kernel mode;
to maximise information collection with minimum observer effect;
the compression of log data;
a managed log message lifecycle;
as much logging on as much of the time as possible;
for privacy to be designed into the logging system;
a common system across macOS, iOS, watchOS, tvOS;
all legacy APIs (NSLog, asl_log_message, syslog, etc.) to be redirected into the new unified log;
to emphasise debugging of macOS and apps, not providing any facilities for system administration or audit;
to link to the sysdiagnose tool for gathering information for bug reports etc.

To achieve this, a log entry is made using a new call that’s handled by the logd daemon and compressed into a buffer. From there it’s either retained in memory if ephemeral, or written out to a file.

There are two main groups of files that store log entries: those kept in /var/db/diagnostics/Persist/ in the form of tracev3 files containing regular log entries, and further tracev3 files in /var/db/diagnostics/Special/ containing additional shorter-life entries. Additional and lengthier log data can be stored in files named by UUID in /var/db/uuidtext/, and there’s also scope for high-volume collection.

tracev3 files use a proprietary compressed binary format that remains undocumented to this day, but has been partially reversed. Apple doesn’t provide direct access to their contents, only through closed-source utilities such as the log command tool. Where users want a more portable format, Apple recommends conversion to a logarchive package, although that’s also undocumented and only directly accessible using log and Console. Apple has in recent years given limited access to the active log for third-party apps, but that lacks many of the useful features of its own log command.

Privacy

Privacy features have caused problems from the start. Log messages containing potentially sensitive information have that censored by <private>. Like so many good ideas, this had unintended consequences as many log entries only contain the dreaded <private>, and in some cases meaningful content is lost altogether.

Ironically, the most embarrassing security problem in the Unified log occurred in early versions of High Sierra, when encryption passwords were leaked apparently as a result of incorrect string formatting. Apple subsequently added an entry field to make explicit the formatting used for that entry.

Until the release of Catalina, there was an undocumented switch to turn privacy protection off, through an option to the log config command. When you needed to view all those censored messages, you could turn protection off, perform the test, and the log then contained all the information you required. That changed in Catalina 10.15. In order to bypass this privacy protection, you had to run your Mac in a special diagnostic mode intended for use exclusively by Apple engineers. Apple later relented and allowed this to be controlled through a profile, although because entries already made don’t contain the censored data, it can’t be applied retrospectively.

When first released, access to the new Unified log wasn’t restricted to admin users, but that changed in macOS 10.12.4, when that restriction was applied, and normal users found they were no longer able to browse the log at all.

Problems

The biggest disappointment, though, has been the Console log browser, which has made only limited use of log entry structure, displays just a small selection of entry fields, provides little aid for the high volume of entries, and worst of all gives no access at all to recent entries in the live log. Apple’s decision to restrict Console to browse the live stream of entries and logarchives has rendered it useless for many of the most compelling reasons for the app, but it has ensured that Console and the log provide no “facilities for system administration or audit”. It has also deterred third-party developers from writing to the log, and made it the exclusive preserve of Apple’s engineers, which perhaps was the original intention.

Since its first release in macOS Sierra, the log has flourished if not grown like an invasive weed. The number of fields available has increased from 16 to over 25, many of them added to support Signposts, introduced in late High Sierra and Mojave. Those are used extensively in macOS primarily to measure performance.

As the log now rolls its tracev3 files to maintain a maximum total file size, rising rates of entries by macOS have limited the period covered by retained entries. What in the early days was sufficient for up to 20 days of entries may now last little longer than a few hours. This also ensures that Console has more limited usefulness, and it struggles to cope with logarchives of any size.

Collection and retention of entries from different subsystems is set in logging profiles, XML property lists stored in /System/Library/Preferences/Logging (in the System volume, so read only) and /Library/Preferences/Logging, which the user controls. You can create your own custom profiles, or modify them on the fly using the log command, although this appears unusual even among the few left who can and do still browse the log.

What used to be a primary tool in diagnosing problems has been abducted without replacement. At least it keeps those pesky system administrators and auditors away.

Leave a Reply

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.