POST

Quick and Dirty Syslog Logging for Games

Look, alright? We all know that you log things out of your games, utilities, and applications. Stdout or files are the norm …

So you’ve likely spent a good deal of time staring at a terminal window or some log file from an application you’re making. You’ve got yourself a nice little suite of applications and tools all outputting to separate windows, files, uh, emails, maybe? If only there were some sort of standardized way of delivering, storing, and aggregating messages into log files, am I right? Yeah, yeah… that’s what Syslog’s been doing for decades.

It’s obscenely old by modern standards and any modern implementation supports trivial delivery via UDP and either comes installed on, or is easy to install on, any platform you’re likely to be working on. Of course there are new and fancy things about that you can use, but the ubiquitous nature of syslog is hard to not appreciate. Good old port 514.

Why

  1. Standard message structure and information
  2. Persistent log information
  3. Log rotation
  4. Central logging for client/server applications

And a close #5 is being stopped from logging in HTML…

Standards Are So Boss

The second you breach the boundary of your own proprietary tools/data and a standard system like Syslog, you gain the ability to utilize any and all approaches, tools, etc. that target that system. Syslog is used the world over for logging on Un*x machines. Systems administrators serve as the market for products whose sole focus is the aggregation and analysis of logs for everything from network health to security forensics.

A Few Tips

The following has helped me get good utility out of my logging, but feel free to ignore it if you find it distasteful in some way.

Syslog Levels

Syslog has a concept of “Facilities” which we won’t get into except to say that one of them is called “User” and is what is most appropriate for this sort of logging. The facility is basically embedded into the integer that represents the level.

The numbers correspond to the levels as such:

  1. Emergency
  2. Alert
  3. Critical
  4. Error
  5. Warning
  6. Notice
  7. Informational
  8. Debug

The “User” facility can be used by adding 8 to any of these. If you’re writing an industrial strength logging system, you’ll want to actually read the specification and do something a little cleaner than adding the magic number ‘8’ to your level. If not, well then leave a comment about “User” and be on your merry way.

Often you will have your own levels more specific to your application (e.g. Error, Warn, Log, Debug, Trace), but it’s just a matter of deciding how you would like to map those to the above levels.

Message Data and Format

Including the following information will help you achieve maximum enjoyment.

  1. Client/Server if applicable
  2. An instance identifier of some sort for seeing multiple runs come through the logs
  3. Log level
  4. The subsystem that the message pertains to.

#1 can be used to triage messages into separate log files if that works out better for you. #4 is mostly for readability, but can also be great for creating scripts that can mine the logs for information.

As an example:

Jan 01 12:30:00 your-host-name SERVER(2a06b95c)[Debug]: AI: Navmesh built. 1200 tris. 3000 connections.

The first pieces of data there, the date/time and host name, are handled automatically by syslog. Everything else is free form. Here I’ve organized it such that it’s both readable at a glance and easily parsed by tools.

Limiting Spam

It’s extremely important that nothing in your logging is flooding so much that important or useful pieces of data are hard to see come through or are getting lost. This is an area where logging to separate files based on some sort of regex or similar can be used.

A high-volume data logging level, which could really be thought of as a “Channel”, can be put into its own files or collections of files so it’s easily toggled off as well as put into a central location for automated analysis. On that latter note, the likelihood of hundreds of lines of logging being something you want to dig through manually is probably pretty low. You can even do some budget analysis using cat/tail/grep/awk/perl from the command line.

The Windowses

Syslog isn’t on Windows by default. I know that. We all know that. But neither is Visual Studio or any other development tool. Just install it.

Use UDP as the delivery mechanism and install syslog-ng via Cygwin.

Cygwin

Yeah, it’s not the dream come true that it could be, but it is indispensable in developing your software in a way that translates cleanly to other platforms, which by and large are Un*x variants in one form or another.

Examples

Syslog-ng Setup

This Syslog-ng setup will create 3 log files (“Destinations”); /var/log/messages, /var/log/game, and /var/log/game_trace ‘messages’ collects anything sent directly to syslog via API calls. ‘game’ will have all messages containing “SERVER”, but not any that have “[TRACE]” ‘game_trace’ will have only messages with “[TRACE]” in them.

@version: 3.2
@include "scl.conf"

source s_local {
    system();
    internal();
};

source s_network {
    udp();
};

destination d_local {
    file( "/var/log/messages" );
};

destination d_game {
    file( "/var/log/game" );
};

destination d_game_trace {
    file( "/var/log/game_trace" );
};

filter f_game {
    match( "SERVER" );
};

filter f_trace {
    match( '.+\[Trace\]:' );
};

filter f_game_general {
    filter( f_game ) and not filter( f_trace );
};

filter f_game_trace {
    filter( f_game ) and filter( f_trace );
};

filter f_everything_else {
    not filter( f_game );
};

log {
    source( s_local );
    source( s_network );
    filter( f_everything_else );
    destination( d_local );
};

log {
    source( s_local ); 
    source( s_network ); 
    filter( f_game_trace ); 
    destination( d_game_trace ); 
};

log { 
    source( s_local ); 
    source( s_network ); 
    filter( f_game_general ); 
    destination( d_game ); 
};

Note: This example is far from perfect and Syslog-ng warns of the performance implications of ‘match’ like that, but we’re really not pushing a volume that would make that an issue

UDP Code Snippets

I ommitted a C/C++ example as it’s somewhat different depending on platform and the C# version just read a little clearer. There are thousands of examples of doing sockets out there on those internets though.

// Setup
IPAddress destinationAddress = IPAddress.Parse( address );
IPEndPoint endPoint = new IPEndPoint( destinationAddress, 514 );
Socket socket = new Socket( AddressFamily.InterNetwork, SocketType.Dgram, ProtocolType.Udp );

// Send
byte[] buffer = System.Text.Encoding.ASCII.GetBytes( "<14>SERVER(2a06b95c)[Info]: AI: Navmesh built. 1200 tris. 3000 connections." );
socket.SendTo(buffer, System.Math.Min(buffer.Length, 512), SocketFlags.None, _endPoint);

Conclusion

At its very core, using syslog instead of your own file based logging gives you the benefit of standards and a wealth of existing tools.

Lastly, there are systems that do syslog logging that obviate the need for you to screw around with UDP directly on your own, such as Poco and, if you’re using C#/.NET, Log4Net.