You'll get your Mac news here from now on...

Help TMO Grow

Subscriber Login

Advertising Info


The Mac Observer Express Daily Newsletter


More Info

Site Navigation

Home
News
Tips
Columns & Editorials
Reviews
Reports
Archives
Search
Forums
Links
Mac Links
Software
Reports
Contact


by Kyle D'Addario
& Wincent Colaiuta


Console Yourself: Understanding Mac OS X Logs
August 3rd, 2001

Underneath the bright and shiny new Aqua interface of Mac OS X comes a completely new Unix foundation that is unlike anything Mac OS users have experienced before. One of the most attractive aspects of this new foundation is the set of industrial-strength networking applications that come with it. We've looked at many of these in previous Hot Cocoa columns. They include things like NFS (Network File System), Samba/CIFS (Windows filesharing), AFP (Apple File Protocol), FTP (File Transfer Protocol) and robust Web serving with Apache, the world's most popular Web server.

As an inseparable part of all this Unix technology we are also welcome to the world of logs. Logs are text files that form a record of what has occurred on the system, much like a journal. This column will serve as an intro to some of the key logs that you'll find on your Mac OS X system. We'll start by looking at the system console log. So if you can't see the wood for the trees, console yourself and delve into the wonderful world of logs...

The console app

Take a look in the Applications/Utilties folder of your Mac OS install you'll find a little application named "Console." If you've ever tried running this app you'll have seen how it likes popping to the front of your screen every now and then and flashing some nearly intelligible textual messages for a second. What this program is actually doing is monitoring a little file called "console.log" that is stored deep down in the filesystem at the following location:

/private/var/tmp/console.log

Everytime something new gets written to that file the Console app flashes its window up to the front and lets you know what's happening. So what sort of things get written to that file? Most often, the answer is error messages and warnings. All programs that are running on the machine will occasionally emit error, warning and status messages in a textual form. If the events they refer to aren't significant enough to demand a user's immediate attention, then they usually get routed to a log somewhere, and it is the console.log that gets many of them.

Unfortunately, the Console application leaves a lot to be desired. This app is a simple front-end to the Unix command line tool "tail." When you run the graphical Console application what it is actually doing is issuing a "tail -f /private/var/tmp/console.log" command behind the scenes, taking the output from that command and displaying it in a pretty Aqua window. (The tail command, as the name suggests, shows the tail end of a file. The "-f" switch instructs the tail command to stay running and "follow" the file, continually watching the end and printing out any additional lines that get written to it.)

A much more impressive way of displaying the console.log file is to use an excellent application called DesktopConsole by Matthew Drayton. This tiny 66 kilobyte app will follow the console.log file (or any other number of text files you nominate) and display them in a transparent window at the very back of your screen. As shown in the screen shot below, this creates the illusion that the log files are actually being written to your desktop picture in real time.

DesktopConsole in action
Click the image for a larger view.

This is the best type of eye candy because it serves a functional purpose in addition to being aesthetically pleasing and unobtrusive. As a quick glance at this thread on the MacNN forums will show, many people have been using DesktopConsole to help them monitor FTP or HTTP (web) access to their machines.

Analyzing logs

These logs can be confusing, even to experienced Unix users. Although I am reasonably familiar with various types of Unix, I still find that there are many, many, many lines in logs that I do not understand. The important message though is don't worry. The reason that programmers send their messages to logs and not into dialog boxes and error messages is that they don't deem them significant enough to bother users. If you see it in a log, it probably won't mean the end of the world.

By the same token, logs can be very useful even though the ordinary user will never have any need to delve into them. For example, logs can provide you with additional diagnostic information when trying to troubleshoot a problem. You might be trying to unmount a FireWire drive by dragging its icon to the trash and you're puzzled at why it's not working. A quick look at the system log might just tell you what's up with some lines like this:

Aug  3 16:39:02 cannondale /sbin/autodiskmount[93]:
 UnmountDisk('disk0s10') unmount('/') failed: 16 (Device busy) 
Aug  3 16:39:02 cannondale last message repeated 8 times
Aug  3 16:39:02 cannondale last message repeated 8 times

What this message means is that on Aug 3 at 16:39 the autodiskmount process tried to unmount a disk and it was unable to because the device was busy. The word "cannondale" here is the machine name. On your machine it might be something different, or it could be "localhost" if you have left things at their default settings.

Apple will be releasing Mac OS X 10.1 at the end of September and my looks at pre-release builds of the new version indicate that the "console.log" file will not be active. Most of the information will instead be routed to the system.log file (which incidentally also exists on pre-10.1 versions of Mac OS X) which can be found at:

/private/var/log/system.log

Like many log files this one is readable only by owner "root" and by members of group "wheel." This means that only a "superuser" or an administrator can look at the file. It's a measure that's intended to increase security in case an unauthorized user or a guest gets a peek at the potentially sensitive information in the log.

To finish off this week's Hot Cocoa column I'll examine a few more entries from the system.log file to demonstrate how they can be read. If you want to learn more about logs then it's a good idea to run a program like DesktopConsole for a few weeks and just keep an eye on a few key files like "console.log" and "system.log" -- and other log files of interest hidden away in /private/var/log/. You'll be surprised at how much you learn just from letting them sit there in the background. Let's start with a couple lines that will be sure to turn up in your logs at some point:

Aug  3 16:39:03 cannondale syslogd: exiting on signal 15
Aug  3 16:40:27 cannondale syslogd: restart

These are the last two entries you'll see in the system.log before a machine reboots. They indicate that the syslogd process (the program that is responsible for writing all these messages to the logs!) has received a signal to quit and the machine is going to restart. (For more info on syslogd type "man syslogd" in the terminal.)

Aug  3 16:40:27 cannondale mach_kernel: b4000000:00800000
Aug  3 16:40:27 cannondale mach_kernel: .Display_Rage128:
 user ranges num:1 start:b6408000 size:180
Aug  3 16:40:27 cannondale mach_kernel: .Display_Rage128:
 using (1x1@0Hz,32 bpp)
Aug  3 16:40:27 cannondale mach_kernel: IOVendorSurface::set_id_mode:
 surface mode contains obsolete bit
Aug  3 16:40:27 cannondale mach_kernel: UniNEnet: Ethernet address
 00:0a:27:e1:09:52
Aug  3 16:40:27 cannondale mach_kernel: ether_ifattach called for en
Aug  3 16:40:27 cannondale mach_kernel: ipfw_load
Aug  3 16:40:27 cannondale mach_kernel: IP packet filtering
 initialized, divert enabled, rule-based forwarding enabled,
 default to accept, logging disabled
Aug  3 16:40:28 cannondale netinfod local[199]:
 setsid failed: Operation not permitted
Aug  3 16:40:28 cannondale lookupd[206]: lookupd (version 222.1)
 starting - Fri Aug  3 16:40:28 2001
Aug  3 16:40:28 cannondale ntpdate[214]:
 ntpdate 4.0.95 Wed Jul  4 11:58:30 PDT 2001 (1)
Aug  3 16:40:30 cannondale ntpdate[214]:
 step time server 17.254.0.27 offset 0.218634 sec
Aug  3 16:40:30 cannondale ntpd[216]:
 ntpd 4.0.95 Wed Jul  4 11:58:20 PDT 2001 (1)
Aug  3 16:40:30 cannondale ntpd[216]: precision = 8 usec
Aug  3 16:40:30 cannondale ntpd[216]:
 frequency initialized -46.089 from /var/run/ntp.drift
Aug  3 16:40:30 cannondale ntpd[216]:
 server time.asia.apple.com minpoll 12 maxpoll 17
Aug  3 16:40:31 cannondale automount[245]: automount version 21
Aug  3 16:40:31 cannondale cron[267]: (CRON) STARTUP (fork ok) 

Next up we see a collection of messages issued during the startup process. The first few lines come from "mach_kernel" which is the process at the very heart of Darwin. There's not much that happens on the system that the kernel doesn't know about, and its the kernel which is responsible for those lovely black and white "panic" messages which appear when something goes really, really wrong. Here we can see the kernel finding the ATI Rage Mobility chipset on my logic board, recognizing my Ethernet interface and enabling packet filtering. The latter is handled by the ipfw program and although it doesn't do much in a default Mac OS X install, it can actually be configured to provide robust firewall functionality (type "man ipfw" for more details).

Following this we see messages coming from a number of other processes during the boot: NetInfo and lookupd both start, and we see network time synchronization kick in courtesy of ntpdate and ntpd. Finally we see automount (the process that automatically mounts removable media like CDs and hot-swappable drives like FireWire hard disks) and cron (the utility that starts various system maintenance functions at pre-determined times) start up.

Even more information about the start up than this is available by issuing the "dmesg" command at the terminal which outputs all of the messages that the kernel has issued since boot time. This is the same material that you would see if you held down Command+V during a boot (to force a "verbose" boot) except this time it's not flying by so fast that you can't read it. Here you'll see information that the kernel emitted before the syslogd process even started, and hence before the messages could be output to the system.log. For example, the following brief excerpt shows the kernel detecting the USB subsystem very early on in the boot process. The two different numeric addresses correspond to the two ports on the back of the computer.

buffer headers and 327 cluster IO buffer headers
AppleUSBOHCI::init
AppleUSBOHCI: config @ 100ef000 (a0002000)
AppleUSBOHCI::init
AppleUSBOHCI: config @ 100f4000 (a0001000)

Conclusion

Like all things with Mac OS X there are two ways to learn about the console and the system logs: firstly, you can read what others have to say about them (like you are now); and secondly, you can go out there and get your feet wet yourself! Have a go with the DesktopConsole app and see what you can find out. There are plenty of useful purposes to which this little application can be put and one of the most useful is as a learning aid. The other is for monitoring all those background processes that Mac OS X runs behind the scenes. These daemons include things like the inbuilt FTP server and web server (which write entries into /private/var/log/ftp.log and into the /private/var/log/httpd/ directory respectively) as well as third party servers like hxd (the Unix Hotline daemon). Because these processes run invisibly in the background, there's no easy way to tell if people are accessing your server at any given time and what they're up to. But keep an eye on the logs and you'll soon see what's happening. Have fun!

Wincent Colaiuta - wincent@macobserver.com

You are encouraged to send Richard your comments, or to post them below.


Most Recent Hot Cocoa Columns

Mac OS X & Firewalls: Part One - The Basics
August 17th

Console Yourself: Understanding Mac OS X Logs
August 3rd

Making NFS Work On Mac OS X
July 23rd

Hot Cocoa Archives

Back to The Mac Observer For More Mac News!


Kyle D'Addario is the assistant editor of The Mac Observer and has logged about as much time on Mac OS X as is humanly possible. Kyle studies Computer-Mediated Communication, whatever that is, at the graduate level, and was a founding member of the original Webintosh team.


Wincent Colaiuta runs Macintosh news and criticism site, wincent.org, and joined The Mac Observer team as a contributor in March 2001. He has worked with computers since 1984, and his interests in that area include Macs, PHP programming and security.



Today's Mac Headlines

[Podcast]Podcast - Apple Weekly Report #135: Apple Lawsuits, Banned iPhone Ad, Green MacBook Ad

We also offer Today's News On One Page!

Yesterday's News

 

[Podcast]Podcast - Mac Geek Gab #178: Batch Permission Changes, Encrypting Follow-up, Re-Enabling AirPort, and GigE speeds

We also offer Yesterday's News On One Page!

Mac Products Guide
New Arrivals
New and updated products added to the Guide.

Hot Deals
Great prices on hot selling Mac products from your favorite Macintosh resellers.

Special Offers
Promotions and offers direct from Macintosh developers and magazines.

Software
Browse the software section for over 17,000 Macintosh applications and software titles.

Hardware
Over 4,000 peripherals and accessories such as cameras, printers, scanners, keyboards, mice and more.

© All information presented on this site is copyrighted by The Mac Observer except where otherwise noted. No portion of this site may be copied without express written consent. Other sites are invited to link to any aspect of this site provided that all content is presented in its original form and is not placed within another .