Logging Errors and Warnings

You can use two interfaces in OS X to log messages: ASL and Syslog. You can also use a number of higher-level approaches such as NSLog. However, because most daemons are not linked against Foundation or the Application Kit, the low-level APIs are often more appropriate.

For software specific to OS X, you should use the ASL interface because it provides more functionality. The Syslog API is the most commonly used logging API on UNIX and Linux systems, so you should consider using it when writing cross-platform software.

Structure Messages with Keys and Hashtags

Historically, log messages have consisted of a text message accompanied by information such as where the message came from, how important it was, and when it was logged. The ASL API structures the entire message as keys and values. There are a number of standard keys listed in /usr/include/asl.h, but you can also create your own keys. To prevent key collisions, you should name your keys using a reverse DNS style. For example, com.example.myCustomKey.

You are also encouraged to include hashtags in your log messages, regardless of what API you use. A hashtag is composed of a hash (#) symbol, followed by at least four non-whitespace characters, terminated by whitespace or the end of the message. Hashtags may not begin with a number. Additionally, any custom ASL key that begins with a hash is treated as a hashtag. The Console application and the logging APIs understand hashtags on OS X v10.6 and later. They do not interfere with normal logging on previous versions of OS X, because they are just part of the message text.

Some suggested hashtags are:

Hashtag

Meaning

#System

Message in the context of a system process.

#User

Message in the context of a user process.

#Developer

Message in the context of software development. For example, deprecated APIs and debugging messages.

#Attention

Message that should be investigated by a system administrator, because it may be a sign of a larger issue. For example, errors from a hard drive controller that typically occur when the drive is about to fail.

#Critical

Message in the context of a critical event or critical failure.

#Error

Message that is a noncritical error.

#Comment

Message that is a comment.

#Marker

Message that marks a change to divide the messages around it into those before and those after the change.

#Clue

Message containing extra key/value pairs with additional information to help reconstruct the context.

#Security

Message related to security concerns.

#Filesystem

Message describing a file system related event.

#Network

Message describing a network-related event.

#Hardware

Message describing a hardware-related event.

The following log messages illustrate the use of hashtags.

 
The volume "Macintosh HD" is almost full. #System #Critical #Filesystem
 
Reloading configuration files. #Marker
 
Too many failed logins from user "Mouse". Possible brute force attack? #Attention #Security #Network
 
Startup items are deprecated. Use a launchd job instead. #Developer
 
While organizing orchestra, expected cowbell but found drums. #Comment #Developer

Set a Log Level

The system logger supports logging at a number of priority levels, as is traditional on Unix-based and Unix-like systems. The priority levels and suggested uses for these levels are:

Log Level

Suggested Usage

Emergency (level 0)

The highest priority, usually reserved for catastrophic failures and reboot notices.

Alert (level 1)

A serious failure in a key system.

Critical (level 2)

A failure in a key system.

Error (level 3)

Something has failed.

Warning (level 4)

Something is amiss and might fail if not corrected.

Notice (level 5)

Things of moderate interest to the user or administrator.

Info (level 6)

The lowest priority that you would normally log, and purely informational in nature.

Debug (level 7)

The lowest priority, and normally not logged except for messages from the kernel.

The system logger in OS X determines where to log messages at any given priority level based on the file /etc/syslog.conf.

It is important to choose the appropriate level for log messages. The system logger discards most low-priority messages, depending on the facility specified. To find out how the system logger decides which facilities and priority levels to log in a given log file, look at the files /etc/asl.conf and /etc/syslog.conf. By default, messages logged at Info and Debug are discarded.

Log Messages Using the ASL API

The ASL (Apple System Logger) API is very similar to the historic Syslog API, but provides additional functionality:

The following code example shows how to log a simple error message:

#include <fcntl.h>
#include <asl.h>
#include <unistd.h>
 
main()
{
        aslclient log_client;
        int cause_an_error = open("/fictitious_file", O_RDONLY, 0);
 
        log_client = asl_open("LogIt", "The LogIt Facility", ASL_OPT_STDERR);
        asl_log(log_client, NULL, ASL_LEVEL_EMERG, "This is a silly test: Error %m: %d", 42);
        asl_close(log_client);
}

A complete explanation of the features of the ASL API is beyond the scope of this document. For more information, see the asl manual page.

Log Messages Using the Syslog API

To use the Syslog API, first call the openlog function. This function associates with a particular facility. You can find a list of facilities in the manual page for syslog.

If you need to write a wrapper function for the syslog function, use the function vsyslog instead. This function is identical to syslog except that it takes a variable argument list parameter instead of a series of individual parameters.

Before your program exits, or when you need to specify a different facility, call closelog. This function resets the facility and logging options to the default settings as though you had never called openlog.

The following code example shows how to log a simple error message:

#include <fcntl.h>
#include <syslog.h>
 
main()
{
        int cause_an_error = open("/fictitious_file", O_RDONLY, 0); // sets errno to ENOENT
        openlog("LogIt", (LOG_CONS|LOG_PERROR|LOG_PID), LOG_DAEMON);
        syslog(LOG_EMERG, "This is a silly test: Error %m: %d", 42);
        closelog();
}

The flags passed to openlog affect the behavior of the syslog function as follows:

These and other flags are described in more detail in the syslog manual page.

In addition to the usual printf format flags, this command supports an additional flag, %m. If this flag appears in the log string, it is replaced by a string representation of the last error stored in errno. This is equivalent to what would be reported if you called perror or strerror directly.

Thus, the code sample above prints the following message to standard output:

LogIt[165]: This is a silly test: Error No such file or directory: 42

Then, the code sample tells the system logger to log that message. As a result, assuming you have not changed /etc/syslog.conf, the system logger broadcasts this message to all users:

Broadcast Message from user@My-Machine-Name.mycompany.com
        (no tty) at 13:28 PDT...
 
Jul 24 13:28:46 My-Machine-Name LogIt[601]: This is a silly test: Error No such file or directory: 42

In this example, the process ID was 601, and the process name was LogIt.

For additional control over what gets logged, you can use the function setlogmask to quickly enable or disable logging at various levels. For example, the following code disables logging of any messages below the LOG_EMERG level (which is one higher than the LOG_ALERT level):

setlogmask(LOG_UPTO(LOG_ALERT));

You might, for example, use this function to disable logging of debug messages without recompiling your code or adding conditional statements.

Messages are Filtered

The logging APIs filter log messages at three points:

The functions in the Syslog API consult the process’s filter to decide which messages to pass to syslogd and which messages to discard. The default filter passes all messages. Use the setlogmask(3) Mac OS X Developer Tools Manual Page function to set the filter.

The functions in the ASL API consult the filter of the ASL client passed to them. Each client can have a different value, which means it is possible to have multiple filters in the same process, although uncommon. The default filter discards debug- and info-level messages. Use the asl_set_filter(3) Mac OS X Developer Tools Manual Page function to set the filter.

There are two levels at which you can override filters—global and per-client—using the syslog command. Both override mechanisms are off by default. Overriding the global filter replaces the filter for the entire system with the one you provide. Overriding per-client replaces the filter for a specific logger client. If both overrides are in effect, the per-client filters replace the global filter for their clients.

The syslogd server receives messages form various sources through many different communications channels. It processes each message and may take many actions, including saving messages in one or more files or databases, forwarding messages to other servers over the network, sending notifications, and so on.

There are two main processing modules. The BSD module reads the /etc/syslog.conf file and follows rules it finds there. The rules in that file have two parts: a selector and an action. The selector is composed of message facility names and log levels. When the facility and/or log level of a message matches the specification of a selector, the module performs the associated action. Typically, the action is to format the message and write it to a log file.

A second output module, the ASL module, performs a very similar sorting and filtering function. The rules for this module are found in /etc/asl.conf. This configuration file is more general-purpose than the syslog.conf file. It allows an administrator to set various parameters to control the functions of the syslogd server. It also typically contains matching rules and actions. When a message matches one of these rules, the module performs the associated action. Many of these actions specify that a message should be saved in the ASL database.

The following code listing shows some example ASL-style rules, with comments explaining them:

# Store everything from emergency to notice.
# This means messages with debug and info log
# level are not saved in the database.
? [<= Level notice] store
 
# All messages from the kernel (PID 0) and launchd
# (PID 1) are stored, no matter what log level.
? [<= PID 1] store
 
# Likewise, all messages from the mail, ftp, local0,
# and local1 facilities are stored.
? [= Facility mail] store
? [= Facility ftp] store
? [= Facility local0] store
? [= Facility local1] store
 
# All non-debug messages from the lpr facility
# are stored.
? [<= Level info] [= Facility lpr] store
 
# All messages from the internal facility are
# ignored, regardless of their log level.
? [= Facility internal] ignore

View and Search Log Messages

Use the Console application (found in /Applications/Utilities) to view log messages from the GUI, or the syslog command to view and search log messages from the command line.

Use the asl API to search log messages programmatically. For details, see the asl_search manual page.

Adopt Best Practices for Logging

Treat your log messages as a potentially customer-facing portion of your application, not as purely an internal debugging tool. Follow good logging practices to make your logs as useful as possible:

In order for the log files to be useful (to developers and users), they must contain the right level of detail. If applications log too much, the log fils quickly fill up with uninteresting and meaningless messages, overwhelming any useful content. If they log too little, the logs lack the details needed to identify and diagnose issues.

Logging excessively makes the log files much harder to use, and decreases the value of the logs to your user (who can’t easily find the important log messages), to you (who can’t easily use the log messages to aid in debugging), and to other developers (whose applications’ log messages are buried under yours).

You should avoid writing your own log files. Using the APIs instead of creating your own logging system is the recommended best practice, and provides several advantages:

If you log debugging information, you should either disable these messages by default or log them at the Debug level. This ensures that your debugging messages don’t clutter up your (and your users’) logs.