Really Simple Consolation

January 3rd, 2006

From time to time, I get dragged into the Mac OS X Console application. Either it’s because I’m printing debugging output via NSLog and Xcode has suddenly stopped showing it in the “Run” window, or I’ve just started seeing some wiggy stuff happen with my computer and I need to check under the hood.

What starts out as an innocent enough expedition often ends up with me scratching my head about something else I see in the Console log. This is the festering trash heap where every programmer’s worst “it couldn’t really happen” nightmare output goes. Well, there’s also a lot of annoying “forgot to remove the NSLog” type innocuous output there, too. But at any rate, I usually feel a little ashamed that I wasn’t aware earlier that such and such app has been unable to open a window for the past 3 days. I wish I could keep up with this stuff, but I don’t want to be one of those nerds who leaves the Console window open all the time just waiting for junk to happen. I want to live!

So I had an idea. I’ll track this junk the way I track all the other junk. With NetNewsWire! What is syndication for? It’s for packaging data in a format conducive to my computer tracking changes in junk over time. I want to “subscribe” to my Console log.

What I’ve come up with is sort of an embarrassing hack, but it does kind of work:

But wait a minute. If it’s an embarrassing hack, then shouldn’t I keep my mouth shut? Why would I want to go spreading my half-assed solutions across the Internet? Isn’t that bad marketing? Yes, but I have ulterior motives:

  1. I sort of want to show it off, anyway.
  2. I need your help.

Yes, you! I need your geeky, unixy, sysloggy help. I’ve got this fun little hack, which I’m now prepared to let you download, because you’ve read along so patiently.

What are you downloading? It’s a small shell tool whose only purpose is to translate your Console log into RSS format. You get no options. You just run it, and hope that you like what you see. If you’re using NetNewsWire, you can “subscribe” directly to the executable. So just put the file somewhere on your disk, and then select “New Special Subscription…” from the File menu. You have to tell NetNewsWire that it’s a “Script,” and then you have to tell it that it’s a “Shell Script,” even though it’s a binary executable.

Now update and see your last 30 console “chunks” directly from NetNewsWire.

What’s a chunk? Aha! Yes, this is where you and the “help” thing come into play. One of the problems with syndicating something large and unwieldy is figuring out how to glom together related items. It would be overwhelming to the point of uselessness if every single line in the Console ended up as a separate feed item. So I have to try to be clever. What I’m doing right now roughly follows this logic: starting at the end of the file, move up line by line, collecting lines into a “chunk” until a line “looks like” it belongs to a particular application. Once a particular application is identified, keep moving up the file, until a line that doesn’t identify an application, or that identifies a different application, appears.

Sounds complicated, huh? Yeah, well that was the easy part. That works great when output looks like this:

2006-01-03 12:23:16.462 Xcode[4453] NOTE: Referenced project...[edited]
2006-01-03 12:23:16.562 Xcode[4453] NOTE: Referenced project...[edited]
2006-01-03 12:23:16.643 Xcode[4453] NOTE: Referenced project...[edited]

See – that’s the “dream chunk.” It is so easy to parse. I could even turn the timestamp into a feed item timestamp. It’s just to beautiful. Then you run into examples like these (grouped together for convenience of presentation):

(event handler):Undefined value
Authentication Service: Started
Jan  3 22:30:50 DanielG5 authexec: executing ...[edited]

Bad boys like this pop up all the time. Isn’t somebody in charge here? Argh – different application services are allowing logging to happen that follows different or no conventions. So my happy little “chunk things together” strategy starts to fall apart.

So I drop this funny little hack in your lap in the hopes that you’ll be inspired to try it out, and if you’re just the kind of thing who enjoys this kind of analysis, you’ll help me come up with a systematic approach for “chunking” the Console log. The real problems are when there’s some really well-defined line like the Xcode examples given above, followed by a dozen lines of output that were spewed by that program’s last “well-defined” timestamped log-point.

I suppose I could compromise and just say “all unidentifiable stuff” goes into a chunk of its own. Then you’d end up with random spewage orphaned from its owner, but it would still be temporally near and therefore show up contiguously in the feed.

A new logic for the tool might be:

  1. Look at this line, does it “look like it starts with a date” and “have a decimal number in square brackets”? If so, try to find lines above it with the same number in the square brackets. Put all of these lines into a feed item with a date of the bottom-most line.
  2. Look at this line, does it look unidentifiable? If so, group it with unidentifiable lines above it until I regain sanity. For consistency, give this feed item the same date as either the chunk below or the chunk above.

I’d be particularly curious to hear the opinions of anybody who’s done this kind of log file parsing before. Heck, one of you is probably going to post a link to something that already does exactly this. That would be beautiful! I’m looking forward to hearing your thoughts.

16 Responses to “Really Simple Consolation”

  1. Alexander Carlin Says:

    I can’t help, but I will applaud you for coming up with this idea. Bravo!

  2. Padraig Says:

    Set it up, but I get no messages in my “Mac OS X Console Headlines”. I checked the element in the XML of the RSS, and it does correctly point to my Console log. I have set it to run as a script, so I’m not sure what the problem is !

  3. Padraig Says:

    Oops – I meant to say ‘Shell Script’

  4. Padraig Says:

    hmm, well its just started working now – guess I had something wrong !

    I might have had the console app open at the same time, which could have been locking the file, I guess ?

  5. Philippe Casgrain Says:

    It works for me, I immediately got 60 entries in NNW. I manually set the executable flag (chmod u+x ConsoleFeed) for it, I don’t know if this was necessary or not.

    One comment: since it’s a binary executable, I’d like to compile it from source rather than just blindly downloading an executable…

  6. Daniel Jalkut Says:

    Padraig: The biggest problem I’ve seen is accidentally forgetting to change the “AppleScript” type to “Shell Script,” but that said, it seems like I’ve seen some flakiness in NetNewsWire when first setting it up to run a binary executable. Once it works it seems to keep working, though!

    Philippe: Glad to know it worked! I can appreciate the desire to have source code for it, but at this point I’m not ready to share that.

  7. Annard Brouwer Says:

    This has been done before but then using perl for monitoring remote sites. I can’t for the life of me find the reference though…

  8. Beau Hartshorne Says:

    Annard, is this what you were thinking of: ?

  9. Beau Hartshorne Says:

    Err: http://www.macgeekery.com/node/86

  10. Ed Says:

    I’m not sure you will be able to get anything close to perfect. I’d go with what you already planned: use the ‘good’ format for chunks (looks like the NSLog format) and glom all the rest together. The problem is that any old app can print to stderr and end up in the console.log file.

  11. alexr Says:

    Combine this with Never Been Seen: http://www.ranum.com/security/computer_security/code/

  12. eric gundrum Says:

    Have you looked at asl.log? According to man syslogd, asl.log is the agregate output of what is sent to syslog using the syslog or asl APIs. It may not contain all that you want to watch, but it seems like a good starting point.

  13. Ozguru Says:

    As Ed pointed out, all sorts of crap gets mixed into the genuine messages. Another approach would be to use syslog.conf to send valid messages to some other location that your parser reads. Under Solaris, I was able to send select syslog messages to a pipe but I am not sure if this can be done in MacOSX. Also, in Tiger, Apple introduced the ASL routines which add extra configuration options.

  14. Adam Bell Says:

    Did you see this today? Great minds…..

    http://dekstop.de/weblog/2006/01/revisiting_aggregators_pt_one/

    Adam

  15. Andre Stechert Says:

    Shameless plug: Splunk does the thing you were asking for (we call it “event aggregation”) and a lot more. It includes RSS feeds. For personal use, it’s free. Of course, we’ve got to pay the bills, so there is also a commercial version that gets priority support, etc. I work there and love it.

    Cheers,
    Andre

  16. Mark Says:

    This really sounds like the sort of thing that Bayesian filtering would excel at. Of course, the filters would have to be trained to recognize the log’s output correctly, but I don’t see why it wouldn’t be consistent enough across different systems to make a generic training file work.

    Take a look at this Wikipedia article for some good background on the process.

Comments are Closed.

Follow the Conversation

Stay up-to-date by subscribing to the Comments RSS Feed for this entry.