Software DevelopmentApril 27, 2018

How to Create, Categorize and Filter iOS Logs

Māris (developer)

We all have heard about logs, we all know what they are and we all use them every day in development and testing process. As an iOS developer, I always try to cover most of the logic with logs for each application layer: networking, database, device layer, user experience, business layer, etc.

By doing so it makes it easier for me, other developers and the QA team to debug the application later on.

Technical details used for this post are:

XCode 9.3
macOS High Sierra 10.13.4
iPhone 8 iOS 11.0.3
Swift 4.1

Why to log?

If you are implementing a new feature in an application, for example, saving user data to device database, you would need to see if the saving process was successful or did it throw error.

To the end-user you might just display an alert with status message, but in logs you can express more detailed information by providing deeper insight in what happened. So if the application tried to save data into database and this process finished with error, you would output the error and all additional information, which could help you to diagnose and prevent the cause of it.

Where can we find logs?

iOS developers can see application logs in XCode IDE (Integrated development environment) debug console. The device, on which the application is running, must be connected to the Mac and launched from XCode.

Other persons can search for application logs just by connecting the Device to the Mac via USB and opening XCode Device and Simulator inspector under the Windows menu and clicking on “open console”.

XCode menu.

Additionally, by entering “Console” into Spotlight Search you will find Device Console application, in which you can see all the logs from iOS, including logs from the application we want to debug.

Are there any problems?

Most often used functions in Swift for creating log messages are `print()` and `debugPrint()`.

Both functions will create a log message and output it in the XCode debug console. But since iOS 10, log messages which are generated with these 2 methods are no longer visible in the Device Console application. So, no one else except the developer can see the logs.

An alternative would be to use `NSLog()` function. It will create a log message which is visible in XCode debug console and in Device Console. It will also append a timestamp and an identifier at the beginning of the log message, whereas `print` will not.

Here you can see the output differences:

print("Hello World!") will produce “Hello World!”
NSLog("Hello World!") will produce “2018-04-24 15:57:56.949900+0300 logger[786:82110] Hello World!”

Even though `NSLog()` log messages will appear in Device Console, there still will be a lot of other OS level logs visible to user too, which makes log reading a lot more difficult, for example, for the QA team.

What can we do about it?

With iOS 10/macOS 10.12 Apple introduced new “unified logging” API. And here we can find our third alternative – `os_log()` function.

This function will produce log messages which are visible in both consoles – XCode debug console and Device Console. This helps the developer fully customize log messages, therefore providing more flexibility with search options in Device Console application.

What ‘os_log’ can provide?

First, let’s take a look at the equivalent of `print(“Hello World!”)` using the new `os_log` function

os_log("%{public}@", "Hello World!")

This is the equivalent for the `print()` function and will give the same output, but with extra information. Now lets look deeper in some of the `os_log` new features which in my opinion can not be ignored:

protection of critical data;
application log categorization.

Protection of critical data

Most of the applications contain some kind of critical data, which must not be publicly visible, for example, login information with username and password or API tokens. For development, it’s fine to set this data visible in XCode debug console, because it is possible that the developer needs to see if the provided values are correct. But what would happen if this data would be still visible in logs in production build? Anyone could see that data. And to access it they would only need to attach the device to the Mac and open the Device Console.

With the new `os_log` developers can define access level of the log message just by adding one of the keywords to the log message:

public;
private.

As you already saw in the previous example with the “Hello World!”, the developer must specify the access level for each message to make it visible and readable in the Device Console. By default, if no keyword is provided, it will be treated as a private log message.

Private log messages are visible only if XCode Debugger is attached, in other case it will just output “<private>” and nothing else.

Lets see an example, where part of log message is public and part of it is private:

import UIKit

struct User {
    var username: String
    var password: String
    var email: String
    
    func printInfo() {
        os_log("Username: %{public}@, password: %{private}@, email: %{public}@", username, password, email)
    }
}

class ViewController: UIViewController {
    
    override func viewDidLoad() {
        super.viewDidLoad()

        let user = User(username: "John the Tester", password: "qwerty", email: "john@example.com")
        user.printInfo()
    }
}

If the application will have debugger attached to it, in Device Console we will see this:

Device Console log message with XCode Debugger attached to the application.

And if application will not have debugger attached to it:

Device Console log message without XCode Debugger attached to the application.

You can see that password value isn’t printed if application does not have XCode Debugger attached to it. This is really useful for securing your logs so that you would not accidently make private data visible.

Application log categorization

Developer can easily read logs from XCode debug console, because the debugger only outputs current application logs and nothing else. Logs are transparent and easy to read.

But QA and others will have a harder time reading logs from Device Console, because it outputs not only specific application logs, but also Operating System logs. And as you can guess, there are a lot of OS log outputs per second.

Device Console log messages for short time period.

Here you can see QA’s perspective if they needed to see a “logger” application log message with current “User” object parameter output; it would be difficult to find it. All these logs in the image are generated in a time period lasting 00:00:00.000431. You can imagine how quickly these logs can be appended to the list.

But there is a really nice solution for this. We can add 3 more parameters to the log message which will provide an option for log categorization and filtering.

It looks like this:

os_log("%{public}@", log: OSLog(subsystem: Bundle.main.bundleIdentifier!, category: "application"), type: OSLogType.debug, "Hello World!")

Good practice is that “subsystem” contains value of your application Bundle ID and “category” – value by your choice which represents application layer from which the log function was called, for example, “network”, “database”, “ui”, “business logic”, “application”, etc.

By adding these extra parameters, you can filter and show only those subsystems that have phrase “com.testdevlab.logger” and category “application” included.

In XCode debug console this log will show your provided category name at the beginning of the log message.

XCode debug console with categorized log message.

By categorizing your application logs, you can create a debug environment where QA could easily search for specific application layer logs and easily understand application work logic.

For example, you could find out, what kind of network requests were made by just filtering out logs containing “network” category.

One more thing – the log type. You can specify different types for log messages, for example, `.debug`, `.info`, `.error`, etc. In Device Console you can choose which log type messages you want to see and filter them out.

By default, Console is hiding all `.debug` log messages, so you need to enable them in the Console “Action” menu.

Device Console menu.

Let’s “wrap” it up

You can use`os_log()` function in your code as is and call it whenever necessary. Or you can create a wrapper around this log function and provide a static value for log categories and other parameters. For example, it would be easier if we wouldn’t need to write a subsystem each time or we could choose a log category from a list, not just write it as a string value each time we want to log something.

Let’s try to define a convenient wrapper for this logging function.

import Foundation
import os.log

/// Wrapper class for os_log function
public class Logger: NSObject {
    
    /// Application layer description
    ///
    /// - app: Application layer log
    /// - ui: User Experience layer log
    /// - network: Networking layer log
    /// - database: Database layer log
    enum Category: String {
        case app, ui, network, database
    }
    
    /// Log accessibility level
    ///
    /// - `public`: Log message will be visible in Console app
    /// - `private`: Log message won't be visible in Console app
    enum AccessLevel: String {
        case `public`, `private`
    }
    
    /// Creates OSLog object which describes log subsystem and category
    ///
    /// - Parameter category: Category, provided predefined log category
    /// - Returns: OSLog
    private func createOSLog(category: Category) -> OSLog {
        return OSLog(subsystem: Bundle.main.bundleIdentifier ?? "-", category: category.rawValue)
    }

    
    /// Prints provided log message with help of os_log function
    ///
    /// - Parameters:
    ///   - category: Category, provided predefined log category
    ///   - access: AccessLevel, log access level
    ///   - type: OSLogType, log type level, for example, .debug, .info, .error
    ///   - message: String, provided log message
    func log(category: Logger.Category, message: String, access: Logger.AccessLevel = Logger.AccessLevel.private, type: OSLogType = OSLogType.debug) {
        switch access {
        case .private:
            os_log("%{private}@", log: createOSLog(category: category), type: type, message)
        case .public:
            os_log("%{public}@", log: createOSLog(category: category), type: type, message)
        }
    }
    
}

We can use this custom log wrapper class anywhere in the code. Just define logger object and initialize it. I prefer to define it as a global variable and include preprocessor macro to check if this is a DEBUG environment, and if it is, only then initialize logger. However, if you do not want to do that, you can just initialize the logger in all environments, not only in DEBUG.

import UIKit

let logger: Logger? = {
    #if DEBUG
    return Logger()
    #else
    return nil
    #endif
}()

struct User {
    var username: String
    var password: String
    var email: String
    
    func printInfo() {
        logger?.log(category: .app, message: "Username: \(username), password: \(password), email: \(email)")
    }
}

class ViewController: UIViewController {
    
    override func viewDidLoad() {
        super.viewDidLoad()
        
        let user = User(username: "John the Tester", password: "qwerty", email: "john@example.com")
        user.printInfo()
    }

}

After running it, you can see your log message in XCode debug console.

XCode debug console showing Logger in action.

One more thing. We can also add more information to the custom log message if we want. Let’s modify the Logger class by adding a filename, function name, number of line and the thread from which the log was called.

And that is it. You do not need to change anything in places where `log()` method is called. Try to run it and you will see in XCode debug console an updated log message like this:

`2018-04-26 14:35:51.240762+0300 logger[1432:351535] [app] [main] [ViewController.swift:25 printInfo()] > Username: John the Tester, password: qwerty, email: john@example.com`

[app] – Log message category
[main] – Thread name, from which the log message was called
[ViewController.swift:25 printInfo()] – File name, line number and the function name where it was called

XCode debug console showing updated Logger in action.

Conclusion

All current logging functions do their job, some better, some worse. There are many ready-to-use libraries with different built-in functionality. It’s up to you to choose which is best suited for your project. But one thing is clear – using logs will help debug your application better in case something will not work as expected. Providing as much details as possible in log messages will make logs much more understandable and easy-to-read.

Here are some useful links: