Our QA guy informed me one day that he doesn’t see our log messages when testing on an iOS 10 device.

“Good morning Siri darling, ” I clicked the round icon on the top right edge of my screen. “I don’t see my NSLog messages, please advise…”

“You should switch to os_log API”, she arrogantly replied. “And please stop asking me how much is 36 times purple, which bear is best or can Chuck Norris beat Thor in a fistfight”.

Thank you Siri, I’ll see what I can do.

Basically, a quick look around our code revealed that our NSLog calls are no longer displayed in the console application. Now, we write our code as a library. This means that our log messages within the app, the ones our QA looks for when testing, were part of a dylib compiled in release. And under those circumstances, NSLog doesn’t work starting with iOS 10.0. What does work? Well, according to Siri, a new API, the os_log API, should do the trick.

What is os_log API, you ask? Well, officially it’s called the “Unified Logging System.” Its function is described as “centralizing the storage of log data in memory and in a data store on disk.”

And so we were faced with quite the conundrum. The new os_log API is the way to go, Siri said so herself, but it’s only available starting with iOS 10.0. We had no choice – we had to use the new API when available, but still use NSLog for the old versions.

How were we to do that?

Goldi-logs and the Three Levels

The new api is well documented. Nevertheless, there are a few points worth considering when switching to it. For instance,  The os_log API offers several log types allowing to determine the log level and filters. The log levels differ by the storage behavior, and one has to consider the trade-off for each log level we use. Out of the five possibilities, three seem the most relevant.

When calling os_log with OS_LOG_DEFAULT log object, the generated messages are stored by default in memory and moved to the data store when the internal implementation decides the memory buffers are filled enough. This log level is probably faster but we must keep in mind that in some cases these logs will not be persistent in a data storage at all (the process’s log memory quota has not been exceeded, the process crashed and so on). In such cases, we may lose essential information.

One might say that info messages are usually not as essential (as opposed to the always persistent error logs for example), but in many cases messages printed throughout the process are important for understanding a specific flow and state.

os_log_error on the other hand always saves the messages in the data store. The more error messages the slower the app is.

Whose iOS Version Is It Anyway?

But enough chitchat. Let’s get down to business – how do we support both NSLog for older versions and the new os_log API for newer versions?

I use 2 conditions to decide between the two. The key is to remember this is Apple we’re dealing with, so we can’t just call an internal os_log API and see if it exists or supported on the current running device. Big Brother Apple doesn’t like that.

First, I defined a macro for determining the current system version:

#define SYSTEM_VERSION_GREATER_THAN_OR_EQUAL_TO(v)
([[[UIDevice currentDevice] systemVersion] compare:v options:NSNumericSearch] != NSOrderedAscending)

Using this macro, I determined if the app is running on iOS 10.0 or higher, and if so I fetch a pointer to the export function ‘os_log_type_enabled’ to determine if the new API is available (if not, I’ll use NSLog as a fallback):

+(BOOL)shouldUseOSLog
{
  BOOL bUseOSLog = NO;
  if (SYSTEM_VERSION_GREATER_THAN_OR_EQUAL_TO(@"10.0"))
  {
    bool(*ptr_os_log_type_enabled)(os_log_t oslog, os_log_type_t type) = os_log_type_enabled;
    if (ptr_os_log_type_enabled != NULL)
    {
      bUseOSLog = YES;
    }
  }
  return bUseOSLog;
}

And there we have it, ladies and gentlemen. A platform-based code for using the appropriate log API. Of course, this method should run once per application session.

So Many Logs, So Little Filter Capabilities

Okay, so now I can log with iOS 10.0 or higher as well. Great. However, I feel like I must share one downside I personally found with this new logging structure. Basically, there isn’t a way to delete the logs of a specific device, only to remove the older messages from the display. And iOS 10 produces a lot of inter-process log messages, so filtering log messages to the interesting categories is very important.

Often while running my app, I want to filter the logs to see its messages, wishing to only see those of the current running session, and not those from former sessions. Achieving that can be tricky. In order to filter out the old sessions, I must first state the filter string in the filter box and only then clean the display. Otherwise, since the log cache is not actually cleaned, setting the filter afterwards simply applies it on the existing cache again, old sessions included.

To Custom Log or Not to Custom Log?

The new OSX Console application introduced with Sierra provides new awesome features, some of which were only available in external apps like iOS Console and such. It also fully supports the new os_log API, which means that messages can be filtered by additional properties. os_log messages can be written to a custom log object with a user-defined subsystem and category. The beautiful thing is that the console application handles them as well.

I prefer it over the default XCode output. While it does indeed display messages of only the running process, it lacks some cool Console features. Anyway you must run your code through XCode in order to see its logs.

Some other Console features I find most useful are the ability to switch logging displays between the OSX machine, connected mobile devices and running iOS simulators, and the ability to perform intersection of filtering results.

SafeDK In-App Protection

Extra Tip: Calling All Methods To Gate Me

Another helpful debugging tool is the ability to detect a method or class scope. When they begin, when they end, what is currently running. I haven’t found this ability in the new os_log API (though I’d be happy to be informed of one if I missed it somehow), so I’ll share with you my methodology.

My method is based on the C cleanup attribute. This attribute sets a pointer to a function being called when the attributed object goes out of scope (actually deallocated). I use this technique to log a method’s enter and exit points with a single log line at the beginning of each logged method.

I set this attribute to a local member I defined at the beginning of a method. When the method exits, the cleanup callback is called with the attributed object as its parameter.

The following snippets show how to leverage this behavior for implementing enter and exit messages of a method.

In the .h file:

//Define an object cleanup attribute:
#define onObjReleased __attribute__((cleanup(objCleanUp)))

//Declare a cleanup callback function, with an NSString* parameter:
void objCleanUp( NSString* __autoreleasing * releasedObject );

//Define a log macro using a local attributes NSString* object:
#define logMethod NSString __autoreleasing * msg onObjReleased = @"";

//Build a message string containing the method name
NSString* someMessage = [NSString stringWithFormat:@"method: %@ enter”, NSStringFromSelector(_cmd)];	
msg = someMessage;
NSLog(msg); // ...or os_log

I use a ‘logMethod’ macro because I need the actual method selector. Wrapping this logic in a helper method will report the helper method’s selector for each log message consecutively. Also, the msg object must be released when exiting the logged method’s scope.

Now in the .m file the callback method definition:

void objCleanUp( NSString* __autoreleasing * releasedObject )
{
  if(releasedObject != nil && *releasedObject != nil && [*releasedObject length] > 0)
  {
    NSMutableString* sMessage = (NSMutableString*)(*releasedObject);
    NSLog(@"%@", [sMessage stringByAppendingString:@" - exit"]);
  }
}

The trick here is that the attributed object is also an NSString* instance whose content is the actual message built by the ‘logMethodImp’ macro.

And there you have it, stating the ‘logMethodImp’ macro produces an enter message with the method name at the beginning of a method, and an exit message with the method name when the method exits.

Logging entrance and exit of a method allows us to see what happens in the scope of a specific method including inside methods down the call stack.

I open this logging option only in development mode, though, since vast usage of it may affect performance: It’s a macro containing some logic which will be duplicated in each appearance in the code, as well as likely to “blow up” the log file.

Logging for the Masses

It’s often said that breaking changes are just an occupational hazard for iOS developers. The recent change to the logging system is no exception. Logs often help us debug or learn any problem, long after the initial development process. Most of the time they’re left like an unturned rock. But when you need it, you need it to work. It’s the first response debugging tool on the scene. Which is why this breaking change was so much different than the rest.

Our project didn’t experience any bugs or crashes. It compiled fine. It was “just” missing logs. This change went under the radar, and could have caught us by surprise in a moment of crisis and need.

If you’re using logs for any purpose whatsoever in your app, I bet you already know of this change. And if you were stumped as to which log to use, then let me reassure you you don’t have to choose. Supporting all versions is in my opinion the right thing to do.