It became apparent that we should have a standard method for logging in our frameworks. Some of use are happily using Cocoa Lumberjack in product apps, but not everybody might share this test. So there was a need to have some sort of looking hooks in our shared library code. This would allow everybody to hook up his own favorite logging framework or simply use NSLog.
In this blog post I am explaining the rationale behind DTLog, new in DTFoundation as of version 1.5.1.
Long time ago I explained how to access the Apple System Log (ASL) facility. There I explained that ASL has many more logging levels than just the one NSLog uses. NSLog only ever logs on level 6 (Info). There are several additional levels that might be useful, so I wanted to support the “official log levels”.
As I mentioned in the introduction I didn’t want to add a dependency to Cocoa Lumberjack and leave this up to the developer. Also there would need to be a method to gain the benefit of different log levels, even if not using a specific framework.
One such benefit should be different macros for the different levels, so that I don’t have to type much more to log an error as opposed to an information or a debug message. Also I would want to have a global logging level so that I could switch to a verbose level if need be.
Finally I didn’t want to introduce extra classes or protocols, if the thing could be solved with a few C-functions and a handler block. Let’s define a block signature that would log all pertinent information:
// block signature called for each log statement typedef void (^DTLogBlock)(NSUInteger logLevel, NSString *fileName, NSUInteger lineNumber, NSString *methodName, NSString *format, ...); |
This block is the one that is supposed to be called in the end if the message level is less than or equal to the globally set log level. So we get log level, file name of the source code file, the line number in the source, name of the method we are logging from and the variable number of parameters we are used to passing to NSLog.
We need methods for setting the block (and copy it from stack to heap), and to specify the global logging level for DTLog. The implementation of that is exceptionally simple:
DTLogBlock DTLogHandler = nil; NSUInteger DTLogLevel = 6; void DTLogSetLoggerBlock(DTLogBlock handler) { DTLogHandler = [handler copy]; } void DTLogSetLogLevel(NSUInteger logLevel) { DTLogLevel = logLevel; } |
We have two global variables – with the extern counterparts defined in the header – and for the block we need to make a copy since blocks are usually created on the stack and this copies it to the heap where it survives the destruction of the stack.
How would this work in practice? At the start up of your app you set the log handler block. Here’s an example that combines the variable arguments with the extra info about the log location.
DTLogSetLoggerBlock(^(NSUInteger logLevel, NSString *fileName, NSUInteger lineNumber, NSString *methodName, NSString *format, ...) { va_list args; va_start(args, format); NSString *logLocation = [NSString stringWithFormat:@"%@ %@:%d %@ - ", [NSDate date], fileName, lineNumber, methodName]; NSString *extFormat = [logLocation stringByAppendingString:format]; NSLogv(extFormat, args); va_end(args); }); |
You cannot directly forward a … parameter to a C-function. Instead you have to get the va_list from it and use that. NSLog has a variant NSLogv which instead of the … parameter has a va_list parameter.
To log something we want to have different macros based on the level, but with the same easy-of-use we are used to from NSLog.
// default level is 6 DTLogInfo(@"info: this is %d", 6); DTLogError(@"error: this is %d", 3); DTLogDebug(@"debug: this is %d", 7); // not logged DTLogSetLogLevel(7); DTLogInfo(@"info: this is %d", 6); DTLogError(@"error: this is %d", 3); DTLogDebug(@"debug: this is %d", 7); // logged |
Now for the real magic, which happens via preprocessor macros. First a few helpers:
// helper to get the current source file name as NSString #define DTLogSourceFileName [[NSString stringWithUTF8String:__FILE__] lastPathComponent] // helper to get current method name #define DTLogSourceMethodName NSStringFromSelector(_cmd) // helper to get current line number #define DTLogSourceLineNumber __LINE__ |
We have a macro that checks if the handler block is set and if the current log level is sufficient to call it.
// macro that gets called by individual level macros #define DTLogCallHandlerIfLevel(minLevel, format, ...) \ if (DTLogHandler && DTLogLevel>=minLevel) DTLogHandler(7, DTLogSourceFileName, DTLogSourceLineNumber, DTLogSourceMethodName, format, ##__VA_ARGS__); |
This common root for the individual logging macros is an if. If no log handler is set this exists right away for least possible overhead. Next it checks the global log level against the one for the message. Only if both criteria are met then the handler block is being called passing all the individual information variables.
// log macro for error level (3) #define DTLogError(format, ...) DTLogCallHandlerIfLevel(3, format, ##__VA_ARGS__); // log macro for info level (6) #define DTLogInfo(format, ...) DTLogCallHandlerIfLevel(6, format, ##__VA_ARGS__); // log macro for debug level (7) #define DTLogDebug(format, ...) DTLogCallHandlerIfLevel(7, format, ##__VA_ARGS__); |
That’s all it takes, and I believe it should be simple enough to understand if read casually. With these macros you can plaster your code with useful messages with varying level. For example to log some frame changes in a subview you would use DTLogDebug. Problematic errors would get logged with DTLogError and if the world is going to end you could even go as far as proclaiming a DTLogEmergency.
Integrating with Logging Frameworks
To integrate this with a third party logging framework you have to set the DTLog global level to max (7), then in the handler block you would convert the ASL level to the corresponding level and call the relevant logging methods.
Here’s how I think it would look for piping into Cocoa Lumberjack:
DTLogSetLoggerBlock(^(NSUInteger logLevel, NSString *fileName, NSUInteger lineNumber, NSString *methodName, NSString *format, ...) { int ddLogLevel = 0; switch (logLevel) { case DTLogLevelWarning: ddLogLevel = LOG_FLAG_WARN; break; case DTLogLevelDebug: ddLogLevel = LOG_FLAG_VERBOSE; break; case DTLogLevelInfo: ddLogLevel = LOG_FLAG_INFO; break; default: case DTLogLevelError: ddLogLevel = LOG_FLAG_ERROR; break; } va_list args; va_start(args, format); [DDLog log:LOG_ASYNC_ERROR level:ddLogLevel flag:LOG_FLAG_ERROR context:0 file:[fileName UTF8String] function:[methodName UTF8String] line:lineNumber tag:nil format:format args:args]; va_end(args); }); |
Anything other than the 4 levels covered by the select would have to be treated the same als errors. When using a logging framework that manages it’s own output logging level then you have to configure DTLog to pass through all levels.
// activate handler block for all levels DTLogSetLogLevel(DTLogLevelDebug); |
Set up like this all log statements call the handler block.
Categories: Recipes