ASL: Logging to a file
As I mentioned in the previous post, every ASL client connection (including the default connection) has a set of file descriptors to which ASL will mirror any message you send through it. The set is initially empty, unless you use ASL_OPT_STDERR
when creating the connection, in which case ASL will add STDERR_FILENO
to it for you.
You can add files to the set with asl_add_log_file
, and you can remove them from it with asl_remove_log_file
:
int asl_add_log_file(aslclient asl, int fd); int asl_remove_log_file(aslclient asl, int fd);
As usual, pass NULL
to these functions to work with the default connection.
The format of the output changed in Leopard. In Tiger, it’s the “raw” format:
220 [Time 1197742037] [Host] [Sender ReadFromASLOnDemand] [PID 848] [UID 501] [GID 501] [Level 4] [Message Content object's class (AppDelegate) isn't the class that the object controller is expecting (NSMutableDictionary)]
That number at the start, which is space-padded to ten characters, is the length of the message, including both the space after the length and the newline at the end.
In Leopard, it’s the “std” format:
Fri Dec 7 20:31:55 Foldable-Mac.local ReadFromASLOnDemand[4188] <Warning>: Content object's class (AppDelegate) isn't the class that the object controller is expecting (NSMutableDictionary)
As you can see, the “std” format is simply the NSLog
format with the addition of the name of the log level.
Speaking of log levels, every file receives all messages sent to the connection, regardless of the connection’s filter mask.
In either format, ASL encodes your message using strvis. strvis is a function for escaping various characters; ASL uses it to escape newlines, tabs, and any non-ASCII characters. That’s right: Any non-ASCII characters that you send to ASL will show up in stderr as escape sequences (but they will be logged correctly). You can see why this escaping is annoying; worse, there’s no way to turn it off. I’ve filed this in RadarWeb, to request a way to turn this “feature” off.
I recommend you always add stderr to the default connection, preferably as early as possible (in main). This way, every time you do something like this, it will show up in the Xcode run log:
asl_log(/*client*/ NULL, ASL_LEVEL_DEBUG, "Number of active frobnitzers: %u\n", [activeFrobnitzers count]);
Another way would be to open your own client connection with the ASL_OPT_STDERR
option (as described above), and use that for all your logging.
Finally, in case you’re wondering, removing a log file from a connection does not close the file. The documentation and header make a rather big point of this.
Next in the ASL series: Searching the log database
April 22nd, 2009 at 06:19:06
I don’t understand where the logging actually pops out if you use the defaults. I’m presuming that the standard procedure is to pick a file name in ~/Library/Logs, call open(…., WRONLY|CREAT|APPEND..) and add that file descriptor to the log. But all this talk of “client connections” makes it sound as if the output will be squirrelled away somewhere by default. But if it is, I can’t figure out where.
April 22nd, 2009 at 15:26:44
As I wrote in “Why ASL?”:
Before you ask where that database is: It’s an implementation detail, as I wrote in “Searching”:
April 23rd, 2009 at 02:01:50
Okaayy… but are these log messages visible outside of you writing your own code to search them? I was expecting them to turn up somewhere in Console.app since that seems to show logs from all manner of applications, but nothing appeared until I opened my own file in ~/Library/Logs and logged to that. It seems rather odd to me that there is a standard logging library that squirrels it away in an unknown place with no standard application that can access them.
And what of log cycling? Am I supposed to take some action to stop logs growing forever?
Implementation detail or not, I’m curious where they end up on Leopard.
April 23rd, 2009 at 02:12:59
They’re only accessible through the ASL API, which Console (in Leopard) is a GUI on top of.
They should.
You probably searched incorrectly. If you logged it with a facility other than com.apple.console, it won’t show under “Console Messages”; you’ll need to switch to “All Messages”, or a custom query tailored to find your messages. If you did use a custom query, either you constructed it incorrectly or you’ve found a bug in ASL.
Console is that standard application.
No; by default, syslogd will automatically delete messages older than 24 hours. See undocumented keys.
As of 10.5.6, /var/log/asl.db. But don’t ever rely on that in shipping code.
April 24th, 2009 at 05:44:11
Well, I write this program:
run it, then I open Console.app, click on All Messages, and it isn’t there. If I search on Supercalifragilisticexpialidocious, it isn’t there.
I wrote some Cocoa classes that open a file in ~/Library/Logs and connect that to the asl_log, and those come out in the file, but not in the All Messages of Console. What does come out in All Messages are calls to NSLog apparently.
I wonder why I have log files from dozens of apps in ~/Library/Logs if this database thingy works and is a good idea. I can’t see much from other apps turning up in All Messages.
April 24th, 2009 at 06:10:11
That explains it, right there. See the syslogd manpage, which says:
Info is the second-lowest level—number 6. (Debug is the lowest, at 7.)
I mentioned this in “Client connections”:
Those are also under Console Messages, as NSLog uses the Console facility. (Again, see “Client connections”.)
Several reasons:
April 26th, 2009 at 21:18:15
Thanks to your help, the mist is slowly clearing for me. One last question is what are “Console messages” for? In the old days a multi-user UNIX system had an actual console. Now that seems a bit redundant. Should we think of this as really important messages or something?
April 27th, 2009 at 00:29:22
The Console Messages query is the successor to the old console.log file in Mac OS X before Leopard. Before, NSLog output went to console.log; now, it goes into ASL with a facility of “com.apple.console”, which is what the Console Messages query looks for.
Previously, writing to /dev/console (or, in an Aqua app, stdout or stderr) would also make messages appear in the appropriate place, but this doesn’t seem to work under Leopard. I should report that as a bug.
I don’t know anything about things that other UNIX operating systems call a “console”, so I can’t speak of any similarities that Apple’s Console app, Console Messages query, or console device may have to it.
January 17th, 2012 at 10:19:08
Yeah, I’m just now finding that this behavior is still present in Lion. It would seem that only NSLog() can put messages into ASL console log such that you can see them using Console.app’s “All Messages”.
I guess this keeps naive asl(3) users from shooting themselves in the foot, flooding the system log with all kinds of fluff and such.
If you want your app to have searchable entries in ASL, it seems that you have to edit /etc/asl.conf setting up a rule to create an individual store for your app.
Using the code below, I couldn’t get any ASL-generated log messages to appear in the console log as viewed via Console.app. Didn’t matter what severity level I chose.
November 30th, 2013 at 14:42:17
A possible reason for Chris’s and Bill’s troubles: if you’re a non-administrator user, you’re not authorized to see your own log messages by default. The workaround is to set ASL_KEY_READ_UID to -1.
This, incidentally, is why DTSendSignalFlag() doesn’t work for non-administrator users.
November 30th, 2013 at 14:42:47
(Or your actual UID if it’s actually secret, obviously.)
November 30th, 2013 at 15:23:11
@Bill: Sorry I didn’t fix your comment’s mangled state before. I’ve digitally restored it as best I could, but the header names got completely munched, so I had to guess. I hope I got it right.
March 13th, 2017 at 08:05:42
WARNING: asl_add_log_file() is completely broken (i.e. does nothing) when compiling on 10.12+. you won’t even get a warning about this if you are compiling your app for older versions too. thanks for another bug apple.