macOS Unified log: 1 why, what and how

When Apple released macOS Sierra 10.12 in September 2016, it brought one of the most fundamental changes since the first Public Beta of Mac OS X: it replaced classical Unix logs with a new unified log.

In the eighteen months since, we have been slowly coming to terms with that – in the case of many users, learning to live without access to the macOS log. What had been a valuable aid in diagnosing startup, wake from sleep, app crash, and many other problems was effectively now inaccessible. Those logs which previously contained key audit information for system administrators were also largely gone too.

This series of articles is an attempt to give a practical overview of the unified log system in Sierra and High Sierra – information which, by and large, is not available elsewhere.

History and aims

Prior to 2014, logs in OS X had been fairly vanilla Unix-style text files, which were readily accessed using the bundled log browser Console and a range of third-party tools, and contained all the usual entries you’d expect. You could watch the Mac’s startup sequences, kernel extensions load, and everything get to work. Many users used to access their logs to check that Time Machine backups were running correctly, and to trace their problems.

mul101

Yosemite and El Capitan brought changes, the most obvious being that the logs were starting to fill up with copious idle chatter from component subsystems in macOS. I complained here that the new messages which were appearing, 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
were making the logs hard to use.

I also complained that in El Capitan there were around 4000 messages appearing in All Messages every 8 or 9 hours. Little did I realise what was just around the corner.

With macOS 10.12 Sierra, in September 2016, Apple replaced that traditional Unix text-based log system with its new unified log. It goals, declared at WWDC in June of that year, were:

  • 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.

If you’re unsure what that means, in terms of the result, just open Console and let it run for a minute or two, while you get on with your work. Then try browsing the messages that it has captured over that brief period.

Architecture

mul102LogdFlow

Compiled code writes a message to the log using the new calls, or a legacy call which is redirected to the new log. This is handled by the logd daemon, which compresses it into a buffer. From there it is either retained in memory if ephemeral, or written out to a file.

There are two main groups of files which store log entries: those kept in /var/db/diagnostics/Persist/ in the form of tracev3 files, containing regular log entries, and those in /var/db/diagnostics/Special/ in tracev3 files, which contain additional shorter-life entries. Some additional Fault and Error log data also appear to be stored in files in /var/db/uuidtext/

.tracev3 files use a compressed binary format which is proprietary to Apple, and undocumented. Apple will not provide direct access to their contents, only through closed-source tools such as the log command tool. Where users want a more portable format, Apple recommends conversion to a .logarchive package. Although Apple has still not documented that, I have discovered all its essential requirements and will describe it in detail later in this series.

Log entries are made at any one of five levels:

  1. Fault – these are always saved to disk, and have additional attached information which can be quite voluminous.
  2. Error – as for Faults.
  3. Default – these are saved to disk, but are normally confined to regular log entries.
  4. Info – these are normally saved to memory, but can be set to go to disk instead, and are regular log entries.
  5. Debug – collection of these has to be specially enabled using the log command.

Privacy features have caused problems from the outset. Although the programmer is supposed to be able to override defaults, static strings are normally passed in full into log entries, but dynamic strings, collections, and objects are by default censored with the text <private>. Bugs in support libraries and the ease of censorship results in many log entries losing all useful content to the dreaded <private>, which in many instances renders log entries information-free.

Not all logs have been bundled into the unified log, though. Among the remaining traditional text-based log files are:

  • daily.out, monthly.out, wifi.log are still active;
  • /var/log/install.log still keeps a valuable log of softwareupdate installations;
  • CUPS still runs its own logs in /var/log/cups;
  • third-party apps such as Adobe’s still run their own text logs;
  • system.log still exists, but is now a wasteland visited only by some legacy software, in my case Google Software Update.

Tools

Apple provides two bundled tools for access to the unified log: the GUI app Console, and the log command tool.

Console is a pale shadow of its former self, and is constrained to working with the live log stream from diagnosticd, or on saved logarchive packages. Early releases in Sierra had a lame predicate editor which made it almost impossible to use for any purpose, but this has steadily improved and is now functional in High Sierra.

Console provides no way of examining any log entries which were written before you opened the app, unless you have saved your logs into a logarchive. Even when you do, complete logarchives are so vast that trying to work with them in Console is intensely frustrating and slow. Using Console to examine log entries which occurred during a previous startup, for instance, is so difficult that it is seldom worth attempting.

The log command tool is extremely powerful, and quite complex in use; it is fully documented in its man page, and has improved significantly in High Sierra. Among its highlights are the live streaming of log entries using
log stream
although this is not an ideal place to use complex predicates, despite their value in sampling its firehose of data. The mainstay use to examine log entries is with
log show
and its many options.

I offer a series of free log browsers and other tools which I believe combine the power of the log command with a much more accessible user interface. Recent versions include features not available in Apple’s tools, including regex search, export to CSV format, and highly flexible formatting.

mul103

LogLogger was an AppleScript app offered from October 2016 to January 2017, which worked as a basic front-end to the log tool and dumped extracts into text files.

consol2241

I then developed Consolation, a Swift app which displays its own log extracts. Its first test release was in February 2017, but was constrained to a single window. A much improved version 2.0 followed a month later, and its last full release was in September 2017.

consolation1001

By then, I had started on the even more sophisticated Consolation 3, whose last beta release was in December 2017. The main work remaining to take that to final release is rewriting its lengthy Help book.

During Sierra’s lifetime, Apple changed log access so that standard user accounts cannot obtain any log entries using Console or the log command; these don’t return errors, but no log entries are shown. To work around this for Consolation, I have an app which will launch Consolation with elevated privileges, enabling access to the logs: RunConsolation.

Blowhole is the only command tool that I know of which can write custom messages to the unified log, so provides access from shell scripts, etc.

woodpile72

Woodpile is a browser for the unified log which works quite differently from Consolation, in analysing entries from the top down. It is the only app which accesses the statistics summaries of log files compiled by logd, and uses those to help the user zoom in on short periods of interest in the log. Its first test version was released in October 2017, and the current beta release is 1.0b6 from December 2017.

I have also developed two more specialist tools which rely on the contents of the unified log. DispatchView is intended for the investigation of problems affecting the DAS and CTS dispatching sub-systems, and shows contemporary excerpts for those sub-systems side by side. The Time Machine Mechanic (T2M2) performs analyses on Time Machine log entries to assess their health for users.

Consolation, RunConsolation, Blowhole, Woodpile, DispatchView, T2M2, and RunT2M2 are all available for free download from Downloads above. Each runs on Sierra and High Sierra.