Creating a better NSLog

So, generally when I write iOS code, I will start with a lot of calls to NSLog, which is a macro that with print the string you send it to the console.

There's a few problems with this.

First of all, whether you know it or not, you can see what's being printed to an iOS device's console even on apps you downloaded from the app store. Up till now, I've been preventing console printing by wrapping my NSLog calls with #if DEBUG followed by #endif. But this gets messy in a hurry, and it's quite easy to forget.

Plus, NSLog is quite busy. It has a lot of information in it, and a lot of it I don't need during development.

Here's what an example NSLog statement looks like:

2014-04-25 20:05:55.226 NHGLogger[5780:60b] Hello World!

Where the first set of numbers is the date and time. This is useful information to me.

The "NHGLogger" is the name of the application that created the log statement. This is completely useless to me while debugging... I know what app I'm running. However... this HAS to go into NSLog, because it's the only way to sort out one app from another when there are tons of apps out there all with developers who aren't courteous enough to wrap their debug log statements in #if DEBUG. The next bit, in the brackets? I literally have no idea what this is. It might be some sort of reference to the block of memory that the NSLog call originated from, or the thread? I have no clue. And the final part is the actual message I wanted to log.

What's more... the operating system considers NSLog statements to be warnings. I doesn't actually do anything about them, but as far as the OS is consider, an NSLog call means a program is trying to log some sort of non-normal behavior.

So, I set out to write my own logging macro, with a few criteria.

• The log must be as easy to use as NSLog() is.

• The log must include the time stamp... I always consider this useful information when logging stuff

• The log must ONLY print to co

The easiest way to avoid the extraneous function is going to be to use a function directly rather than using a macro. You do unfortunately have to drop down to a bit of C, but luckily since ObjC integrates rather pleasantly with C, it proves to not be very painful. The only C part is the use of the stdarg.h variable arugment list related items. (This is actually how NSLog works under the hood.)

Declaration:

void NHLog(NSString* format, ...);

Definition:

void NHLog(NSString* format, ...)
{
#if DEBUG
    static NSDateFormatter* timeStampFormat;
    if (!timeStampFormat) {
        timeStampFormat = [[NSDateFormatter alloc] init];
        [timeStampFormat setDateFormat:@"yyyy-MM-dd HH:mm:ss.SSS"];
        [timeStampFormat setTimeZone:[NSTimeZone systemTimeZone]];
    }

    NSString* timestamp = [timeStampFormat stringFromDate:[NSDate date]];

    va_list vargs;
    va_start(vargs, format);
    NSString* formattedMessage = [[NSString alloc] initWithFormat:format arguments:vargs];
    va_end(vargs);

    NSString* message = [NSString stringWithFormat:@" %@", timestamp, formattedMessage];

    printf("%s\n", [message UTF8String]);
#endif
}

Anyway, on to a bit of a critique. The first problem that comes to mind is that I would always rather have too much information than not enough. Imagine if everyone used some kind of logging facility like this. Suddenly you'd have logging statements coming from who knows where for who knows what reason.

Yes, people realy shouldn't leave debug statements in production code, but unfortunately people do and they do it a lot (just look at the incredibly widespread abuse of NSLog...). Then again, as long as you don't leave any of these statements lying around, you're correct that there's no need for extra information. Considering you plan on using this only in your end applications and not leaving it in library type code, it's probably better to not put anything more than the bare essentials.

The other problem is perhaps a bit more obscure. Static variables are inherently unsafe in a non single threaded environment. Technically speaking, your timeStampFormat is unsafe unless you always run NHLog from the same thread (or you initialize it on one thread). The race condition only exists until timeStampFormat is actually created so it's a relatively small window, and the damage would likely be minimal, but considering how common threading is in ObjC applications, it seems an unacceptable flaw.

Unfortunately though, I'm not quite sure how to get around that in a non-expensive way. You could use a mutex, but that adds a very meaningful overhead, and you could use thread local storage, but that is going to bring you deep into C land since -[NSThread threadDictionary] is not available to iOS (you would have to use pthread_getspecific with a raw, non-managed, C-style pointer).

Since we're already edging into C, have you considered strftime? It's much more primitive than NSDateFormatter`, but it should be fit your needs fine, and I can't imagine anything being faster than it. Also, it wouldn't have a costly formatting object to initialize, so you don't have to worry about thread safety.

StackExchange Code Review Q#48204, answer score: 7