Published on

Suppressing Noisy Log Output (NSLog)

Introduction

I was logging scrollView delegate method calls to observe the call order, only to find my console flooded with completely unrelated log messages. I couldn't stand it anymore.

About NSLog

NSLog is defined as:

FOUNDATION_EXPORT void NSLog(NSString *format, ...) NS_FORMAT_FUNCTION(1,2);
FOUNDATION_EXPORT void NSLogv(NSString *format, va_list args) NS_FORMAT_FUNCTION(1,0);

In most cases, to suppress debug logs in production, we replace NSLog with a macro:

#ifdef DEBUG
#define MyLog(format, ...) NSLog(format, ## __VA_ARGS__)
#else
#define MyLog(format, ...)
#endif

Or a more detailed version:

#ifdef DEBUG
# define MyLog(fmt, ...) NSLog((@"[File:%s]\n" "[Function:%s]\n" "[Line:%d] \n" fmt), __FILE__, __FUNCTION__, __LINE__, ##__VA_ARGS__);
#else
# define MyLog(...);
#endif

__VA_ARGS__ is a variadic macro — not widely known, but it was introduced in the C99 standard. The ## prefix before __VA_ARGS__ serves to strip the preceding comma when no variadic arguments are passed, preventing compilation errors.

__FILE__ is replaced by the current source file name at preprocessing time.

__LINE__ is replaced by the current line number at preprocessing time.

__FUNCTION__ is replaced by the current function name at preprocessing time.

Replacing NSLog

//... is the macro notation for variadic arguments; __VA_ARGS__ is the predefined macro for accessing them
#define NSLog(...) MyLog(__VA_ARGS__)

//Custom print implementation
void MyLog(NSString *str,...){
    va_list ap;
    va_start(ap, str);
    int flag = va_arg(ap, int);
    if (flag == -1) {
        NSLogv(str, ap);
    }
    va_end(ap);
}

About va_start and va_end

Since C doesn't support function overloading, handling variable numbers of function arguments is more involved. In a process, the stack grows from high to low addresses. When a function is called, its argument list is pushed onto the high-address portion of the stack, followed by the return address, then the function's executable code. The stack address decrements throughout this process. (Some exploits work by modifying the return address on the stack to redirect execution to injected code.) Here's an illustration:

func( Type para1, Type para2, Type para3, ... )
{
      /****** Step 1 ******/
      va_list ap;
      va_start( ap, para3 ); //The second argument must be the parameter immediately before ...

      /****** Step 2 ******/
      //ap now points to the first variadic argument
      //Use va_arg to retrieve its value

      Type xx = va_arg( ap, Type );

      //The Type must match, e.g.:
      //char *p = va_arg( ap, char *);
      //int i = va_arg( ap, int );
      //Continue calling va_arg for additional arguments
      /****** Step 3 ******/
      va_end(ap); //For robustness
}

In plain terms: va_start sets ap to point to the argument after para3 (the second argument to va_start must be the parameter immediately before ..., in order to locate the first variadic argument). va_arg(ap, Type) retrieves the variadic argument of the given type and advances ap to the next argument. Finally, va_end(ap) resets ap for robustness. So in practice, you'd add an extra -1 argument: NSLog(@"%@", -1, @"tableView"); — this allows the message to print. Calls without the -1 argument will be filtered out.

Although this works in a test project, it keeps breaking when applied to a real project. Two days of debugging and I still couldn't get it working. This approach appears to be a dead end.

Macro Replacement

The final approach is to modify the NSLog macro in the prefix header file, replacing it entirely with a macro that only prints when the log string starts with _:

#ifndef NSLogKey
#define NSLogKey @"_"
#endif


#ifndef __OPTIMIZE__
# define NSLog(s, ...) {if ([s hasPrefix:NSLogKey]) {NSLog( @"%@:%d %@", [NSString stringWithUTF8String:__PRETTY_FUNCTION__], __LINE__,[[NSString stringWithFormat:(s), ##__VA_ARGS__] substringFromIndex:1]);}}
#else
# define NSLog(...) {}
#endif

Miscellaneous

If your project uses DDLog, just commenting out [DDLog addLogger:[DDTTYLogger sharedInstance]]; will do. At this point, most LLDB output is gone. There may still be some logs from third-party SDKs, but they're much less distracting.