Apr 03

My previous post about conditional logging received quite a few responses, with several people pointing out that littering your code with #ifdef DEBUG statements is both ugly and error prone. Karl Kraft, for example, created a new DebugLog class as a drop-in replacement for NSLog.

Since NSLog has been around for quite a while, there have been many solutions to this problem.

CocoaDev suggests this macro:

#if MY_DEBUG_FLAG
#define DEBUG_OUTPUT( a )         NSLog( a )
#define DEBUG_OUTPUT1( a, b )     NSLog( a, b )
#else
#define DEBUG_OUTPUT( a )         // (a)
#define DEBUG_OUTPUT1( a, b )     // (a,b)
#endif

Enumerating all the variants with different number of parameters gets a bit tedious, so with Objective-C 2.0 C99 you can use varargs macros:

#define DEBUG_OUTPUT(fmt, ...) NSLog(fmt, ## __VA_ARGS__)

As described by Fraser Hess in Dropping NSLog in release builds you can put this in your <AppName>_Prefix.pch file:

#ifdef DEBUG
#    define DLog(...) NSLog(__VA_ARGS__)
#else
#    define DLog(...) /* */
#endif
#define ALog(...) NSLog(__VA_ARGS__)

Use ALog for cases where you always want log output regardless of the state of the debug flag. I like this preprocessor macro approach because you don’t have to carry around extra classes in all your projects. Just a few lines of code to paste into one file in your project.

But I think we can improve it further.

The built-in macro __PRETTY_FUNCTION__ is pretty nifty in that it outputs the name of the class and the method where it’s running. Mark Damon Huges uses this in his Cocoa logging macro:

#ifdef DEBUG
// DLOG takes a format argument (which must begin %s) and 0 or more args:
// DLOG(@"%s");
// DLOG(@"%s: %d", x);
#define DLOG(fmt, ...) NSLog(fmt, __PRETTY_FUNCTION__, ##__VA_ARGS__)
#else
#define DLOG(...)
#endif

A drawback with this macro is that it requires you to add a “%s” to all your log statements, e.g. DLOG(@”%s foo”); instead of NSLog(@”foo”);. So it’s not a drop-in replacement for NSLog.

Let’s try to fix that.

#define DLog(fmt, ...) NSLog((@"%s " fmt), __PRETTY_FUNCTION__, ##__VA_ARGS__);

Now you can do DLog(@”foo”); as well as pass in parameters like DLog(@”value: %d”, x);

One final touch is to add the line number:

#define DLog(fmt, ...) NSLog((@"%s [Line %d] " fmt), __PRETTY_FUNCTION__, __LINE__, ##__VA_ARGS__);

Now if you’re lazy and you want to know that execution has reached a particular line, you can just use DLog();

So here is the complete listing of the macro:

// DLog is almost a drop-in replacement for NSLog
// DLog();
// DLog(@"here");
// DLog(@"value: %d", x);
// Unfortunately this doesn't work DLog(aStringVariable); you have to do this instead DLog(@"%@", aStringVariable);
#ifdef DEBUG
#	define DLog(fmt, ...) NSLog((@"%s [Line %d] " fmt), __PRETTY_FUNCTION__, __LINE__, ##__VA_ARGS__);
#else
#	define DLog(...)
#endif

// ALog always displays output regardless of the DEBUG setting
#define ALog(fmt, ...) NSLog((@"%s [Line %d] " fmt), __PRETTY_FUNCTION__, __LINE__, ##__VA_ARGS__);

Set the DEBUG variable in your project as described previously. Update: If your project is 3.0 you may need to set the DEBUG variable this way.

I’m sure there will be further improvements to this. Comments are open as always.

written by Nick \\ tags:

28 Responses to “The Evolution of a Replacement for NSLog”

  1. Peter Hosey Says:

    The __VA_ARGS__ identifier is actually part of C99; it’s not an Objective-C extension. As such, you can use it in Objective-C 2, Objective-C 1, and even straight C, as long as you have the compiler set to either C99 or GNU99.

  2. Nick Says:

    @Peter: You are correct. Post updated. Thanks!

  3. Thomas Says:

    Thanks for this blogpost. I copied the complete listing to the myproject_Prefix.pch file of my iPhone project, but when I try to build I get the following error:

    Precompiling myproject_Prefix.pch (1 error)
    error: macro names must be identifiers

    Any idea what’s wrong?

  4. Nick Says:

    @Thomas: I have copied and used the text from this blog post several times without problems. (One of the reasons I write this blog is to collect code snippets like this in one place.)

    Make sure that the three dots have not turned into an ellipsis, and that the quotes have not turned into “smart quotes”. If that does not help, try removing lines until it compiles.

    I recently noted that the macro code has been incorporated into a cool Xcode template project: iphone-static-library-project-template. So another option could be to download the code from there.

  5. Taber Says:

    thanks for the nice post. i had the same problem as thomas – switching to using “OTHER_CFLAGS $(value) -DDEBUG=1”
    seemed to fix!

  6. Snippet: Debug Macros at Under The Bridge Says:

    […] -[MyAppDelegate myFunction:]:did time intensive stuff Time = 1.2345678 Also check out  The Evolution of a Replacement for NSLog for another take on handy macro […]

  7. mare Says:

    Mmm, I tried to test my project in some not yet published SDK and it now fails with the same error as the people above had. I tried all their solutions but none works. Anybody got another bright idea. It would be a shame to have to remove all those nice DLog statements….

  8. Nick Says:

    If you get “error: macro names must be identifiers”, then make sure you have defined DEBUG properly.

    If you are using OTHER_CFLAGS then set the value to -DDEBUG=1, if you are instead using GCC_PREPROCESSOR_DEFINITIONS then the value needs to be just DEBUG=1

  9. mare Says:

    If you are using OTHER_CFLAGS then set the value to -DDEBUG=1, if you are instead using GCC_PREPROCESSOR_DEFINITIONS then the value needs to be just DEBUG=1

    That was it. Thanks!

  10. Jarek Says:

    Good post, smart technique. And easy to implement. Finally I’ll get rid of all debug text from my releases.

    Thanks

  11. Al Says:

    Just incase anyone is as stupid as me and does a search and replace to change all existing NSLog calls to DLog – remember that the .pch file should not be included in this search!

    The error message: implicit declaration of function DLog had me confused for a while until I realised I had also changed the definitions in the pch file!

    Doooh.

  12. links for 2009-06-11 | manicwave.com Says:

    […] The Evolution of a Replacement for NSLog | iPhone Development Blog an intelligent NSLog replacement (tags: iphone debugging logging) […]

  13. Dave Says:

    Thanks for the handy logging code!

    Just in case anyone has this same problem:

    When I tried to add a User Defined GCC_PREPROCESSOR_DEFINITIONS I received the error that this was already defined, although I couldn’t find it anywhere.

    Instead I had to go to Show: All Settings and find: Preprocessor Macros under the GCC 4.2 – Preprocessing section and add DEBUG=1 to that item.

    It seems Preprocessor Macros and GCC_PREPROCESSOR_DEFINITIONS are the same thing?

    I’m using the 3.0 sdk if that matters…

  14. Steven Fisher Says:

    DLog(aStringVariable) isn’t really safe or useful anyway, unless you’re sure the string won’t contain any % sequences. And if you knew what the string was, you wouldn’t really need to log it. If it’s worth doing, it’s worth doing right.

    (It’s usually a security issue, too, but I don’t think that matters for a macro that isn’t going to be in release builds.)

  15. Bill Hollings Says:

    Just came across this posting. Thanks for some great ideas here, Nick!

    After reading this blog entry, I took these ideas, along with some other typical logging ideas such as logging levels, and created a Logging.h header file. In the spirit of appreciation, I thought I’d contribute the code from that file back to this thread. The code below can be used as-is…just paste it into a central header file somewhere (as mentioned, we created a Logging.h file). There are a series of switches that can be set to customize formats, and turn specific logging levels on and off, or remove logging altogether.

    I hope this proves useful to someone.

    …Bill Hollings

    /*
    * There are three levels of logging: debug, info and error, and each can be enabled independently
    * via the LOGGING_LEVEL_DEBUG, LOGGING_LEVEL_INFO, and LOGGING_LEVEL_ERROR switches below, respectively.
    * In addition, ALL logging can be enabled or disabled via the LOGGING_ENABLED switch below.
    *
    * To perform logging, use any of the following function calls in your code:
    *
    * LogDebug(fmt, …) – will print if LOGGING_LEVEL_DEBUG is set on.
    * LogInfo(fmt, …) – will print if LOGGING_LEVEL_INFO is set on.
    * LogError(fmt, …) – will print if LOGGING_LEVEL_ERROR is set on.
    *
    * Each logging entry can optionally automatically include class, method and line information by
    * enabling the LOGGING_INCLUDE_CODE_LOCATION switch.
    *
    * Logging functions are implemented here via macros, so disabling logging, either entirely,
    * or at a specific level, removes the corresponding log invocations from the compiled code,
    * thus completely eliminating both the memory and CPU overhead that the logging calls would add.
    */

    // Set this switch to enable or disable ALL logging.
    #define LOGGING_ENABLED 1

    // Set any or all of these switches to enable or disable logging at specific levels.
    #define LOGGING_LEVEL_DEBUG 1
    #define LOGGING_LEVEL_INFO 1
    #define LOGGING_LEVEL_ERROR 1

    // Set this switch to set whether or not to include class, method and line information in the log entries.
    #define LOGGING_INCLUDE_CODE_LOCATION 1

    // ***************** END OF USER SETTINGS ***************

    #if !(defined(LOGGING_ENABLED) && LOGGING_ENABLED)
    #undef LOGGING_LEVEL_DEBUG
    #undef LOGGING_LEVEL_INFO
    #undef LOGGING_LEVEL_ERROR
    #endif

    // Logging format
    #define LOG_FORMAT_NO_LOCATION(fmt, lvl, …) NSLog((@”[%@] ” fmt), lvl, ##__VA_ARGS__)
    #define LOG_FORMAT_WITH_LOCATION(fmt, lvl, …) NSLog((@”%s [Line %d] [%@] ” fmt), __PRETTY_FUNCTION__, __LINE__, lvl, ##__VA_ARGS__)

    #if defined(LOGGING_INCLUDE_CODE_LOCATION) && LOGGING_INCLUDE_CODE_LOCATION
    #define LOG_FORMAT(fmt, lvl, …) LOG_FORMAT_WITH_LOCATION(fmt, lvl, ##__VA_ARGS__)
    #else
    #define LOG_FORMAT(fmt, lvl, …) LOG_FORMAT_NO_LOCATION(fmt, lvl, ##__VA_ARGS__)
    #endif

    // Debug level logging
    #if defined(LOGGING_LEVEL_DEBUG) && LOGGING_LEVEL_DEBUG
    #define LogDebug(fmt, …) LOG_FORMAT(fmt, @”debug”, ##__VA_ARGS__)
    #else
    #define LogDebug(…)
    #endif

    // Info level logging
    #if defined(LOGGING_LEVEL_INFO) && LOGGING_LEVEL_INFO
    #define LogInfo(fmt, …) LOG_FORMAT(fmt, @”info”, ##__VA_ARGS__)
    #else
    #define LogInfo(…)
    #endif

    // Error level logging
    #if defined(LOGGING_LEVEL_ERROR) && LOGGING_LEVEL_ERROR
    #define LogError(fmt, …) LOG_FORMAT(fmt, @”***ERROR***”, ##__VA_ARGS__)
    #else
    #define LogError(…)
    #endif

  16. Nick Says:

    Thanks Bill!

  17. Glen Byram Says:

    Thanks for this awesome piece of work.
    I am very new to iphone programming. The language itself is a lot different to the mainframe stuff I did. Then there’s the pre-processor – which I still don’t understand fully – but getting there.
    I had a problem with the code as presented above. I copied it to my iphone project, ensured DEBUG was 1 for debug stuff and 0 for release stuff.
    However, the output statements were generated – even on a release. I looked at the pre-compiled output and sure enough the correct DEBUG setting was being used. To cut a long story short, my investigations suggested that I should be using #if DEBUG, not #ifdef DEBUG.
    Switched the code above to #if and everything is now fine. Not sure what I missed along the way but surely just checking if DEBUG is defined is incorrect? Please feel free to correct me and let me know what I missed.

  18. Nick Says:

    @Glen: The way the #ifdef preprocessor command works is that it looks to see if the variable following #ifdef has been defined at all. If it has been defined, regardless of it’s value, then the statements following #ifdef will be included in the compilation. So in your case where you defined DEBUG = 0, #ifdef found that DEBUG had been defined, and thus included the logging code that followed.

    When you changed the code to #if DEBUG, the preprocessor now checks for the value of the DEBUG variable. When it’s zero, the following statements are ignored and when it’s anything but zero the following statements are included.

    Both ways work equally well, and it’s more a style issue or personal preference, which one you use.

  19. Susan Says:

    What if I needed DLog() to *NOT* show all that wasted info about the exact date/time/second… 100s of times?

  20. Nick Says:

    @Susan: You could define DLog() to be NSLog() and just use the DEBUG flag to enable/disable it, if you don’t want the extra information provided by the DLog() macro. But I don’t think you can suppress the timestamp.

  21. Donna Says:

    Where would be a good place to put all that #Define code?
    And how would I include it in *EVERY* file in *ALL* my apps?

  22. Nick Says:

    @Donna: Place the macro code in your Prefix.pch file in each project. This will automagically include it in all files in the project.

  23. Tom Says:

    @Donna You can also edit the (several) template pch files located in
    /Developer/Platforms/iPhoneOS.platform/Developer/Library/Xcode/Project Templates/Application//[iPhone|iPad] Application/___PROJECTNAMEASIDENTIFIER____Prefix.pch

    and add the DLog definition code. Remember that its always a good idea to back up any template files before you start modifying them 🙂

  24. Tom Says:

    And another thought — if you add the DLog definition code and then do a global find/replace for NSLog/DLog, you will end up changing the code in the pch file as well.

    (Obvious, I know, but this gets me every time — and it takes me several minutes to figure out why the code won’t compile)

  25. numist Says:

    With regards to your ‘// Unfortunately this doesn’t work DLog(aStringVariable); you have to do this instead DLog(@”%@”, aStringVariable);’, this can be fixed by dynamically creating an NSString in the macro to hold the user’s format and arguments, like so:

    # define DLog(fmt, …) NSLog((@”%s [Line %d] %@”), __PRETTY_FUNCTION__, __LINE__, [NSString stringWithFormat:(fmt), ##__VA_ARGS__]);

    hope this helps.

  26. Neal Ehardt Says:

    Great help, thank your for the blog post! I’m a bit of a perfectionist so here’s the DLog that works for me. It prepends your output with a fixed-length string consisting of the Time, Function, and Line. For my purposes (a UI-heavy iOS client) these are the most relevant pieces of data.

    Here’s some sample output — it looks much nicer in monospace. Notice that the class name and message name are treated as separate strings, so a long class name won’t obliterate a long message name. Works with blocks and C-functions too.

    19:24:18.099 -[MyApplctnAp.. application:didFinishLa..]@28 App initializing…
    19:24:18.212 -[UserLibrary getDeviceArtistsAndSongs]@118 querying user library
    19:24:20.179 -[MyApplctnViewController activate]@93 actually activating…
    19:24:20.180 cFoo @86 printing from C function
    19:25:03.031 -[ScrollerController addMagazine:]@85 addMagazine Tyler, The Creator
    19:25:03.234 -[ScrollerController pageTurnedFrom:to:]@201 0 -> 0
    19:27:39.703 __+[GUtil asyncImageFrom..]_block_invoke_1@59 restarting async image load
    19:29:57.541 -[MusicPage assembleAlbumView:]@121 image loaded

    Enjoy!

    ///// ====== MyApplctn.h ======

    #define DEBUG
    #import “LogUtils.h”

    ///// ====== LogUtils.h ======
    #import

    // ALog always displays output regardless of the DEBUG setting
    #define ALog(fmt, …) [LogUtils logString:[NSString stringWithFormat:fmt, ##__VA_ARGS__] fromMethod:[NSString stringWithUTF8String:__PRETTY_FUNCTION__] atLine:__LINE__];

    // DLog is almost a drop-in replacement for NSLog
    // DLog();
    // DLog(@”here”);
    // DLog(@”value: %d”, x);
    // Unfortunately this doesn’t work DLog(aStringVariable); you have to do this instead DLog(@”%@”, aStringVariable);
    #ifdef DEBUG
    # define DLog(fmt, …) ALog(fmt, ##__VA_ARGS__)
    #else
    # define DLog(…)
    #endif

    @interface LogUtils : NSObject

    + (void)logString:(NSString *)str fromMethod:(NSString *)method atLine:(int)line;

    + (NSString *)forceString:(NSString *)str toLength:(int)chars;

    @end

    //// ====== LogUtils.m ======

    #import “LogUtils.h”

    @implementation LogUtils

    static NSDateFormatter *dateFormatter;

    + (void)logString:(NSString *)str fromMethod:(NSString *)method atLine:(int)line {

    if(dateFormatter == nil) {
    dateFormatter = [[NSDateFormatter alloc] init];
    [dateFormatter setDateFormat:@”HH:mm:ss.SSS”];
    }
    NSString *time = [dateFormatter stringFromDate:[NSDate date]];

    int METHOD_LENGTH = 42;
    NSRange openRange = [method rangeOfString:@”[“];
    NSRange closeRange = [method rangeOfString:@”]”];

    if(openRange.location == NSNotFound || closeRange.location == NSNotFound) {
    method = [LogUtils forceString:method toLength:METHOD_LENGTH];
    } else {
    // looks like it’s an Objective-C method
    // get fancy and abridge both the class and the message separately

    NSString *prefix = [method substringToIndex:openRange.location+1];
    NSString *meat = [method substringWithRange:NSMakeRange(openRange.location+1, closeRange.location – (openRange.location+1))];
    NSString *suffix = [method substringFromIndex:closeRange.location];

    float classToMessageRatio = .5;
    int N = METHOD_LENGTH – prefix.length – suffix.length;
    NSString *dots = @”..”;

    NSRange spaceRange = [meat rangeOfString:@” “];
    NSString *class = [meat substringToIndex:spaceRange.location];
    NSString *message = [meat substringFromIndex:spaceRange.location];

    if(meat.length <= N) { while(class.length + message.length N; n--) { float curRatio = (float)classLength / messageLength; if(curRatio < classToMessageRatio) { messageLength--; } else { classLength--; } } if(classLength != class.length) { int k = classLength - dots.length; class = [[class substringToIndex:k] stringByAppendingString:dots]; } if(messageLength != message.length) { int k = messageLength - dots.length; message = [[message substringToIndex:k] stringByAppendingString:dots]; } } method = [NSString stringWithFormat:@"%@%@%@%@", prefix, class, message, suffix]; } NSString *lineString = [LogUtils forceString:[NSString stringWithFormat:@"%d", line] toLength:4]; NSString *output = [NSString stringWithFormat:@"%@ %@@%@ %@", time, method, lineString, str]; printf("%s\n", [output cStringUsingEncoding:NSUTF8StringEncoding]); } + (NSString *)forceString:(NSString *)str toLength:(int)chars { if(str.length <= chars) { while(str.length < chars) str = [str stringByAppendingString:@" "]; return str; } NSString *dots = @"..."; if(str.length <= dots.length) return [dots substringToIndex:str.length]; return [[str substringToIndex:chars - dots.length] stringByAppendingString:dots]; } @end

  27. How To Download a File Only If It Has Been Updated | iPhone Development Blog Says:

    […] See this post for the source to the DLog […]

  28. Eric Says:

    Quite a lot of info here, thanks everyone, you saved me precious hours of work. Just my 2 cents: when copying/pasting code above, beware in the copy/paste process some HTML characters end up offending the compiler 🙂 such as “…” (in the vararg part of macros) that has to be changed to three actual dots, or double-quotes that have to be changed to an actual ASCII double quote. Hope that’ll save new readers a few precious minutes

Leave a Reply