Logs in iOS episode 1: os_log

Imagine that you are sitting down to make a new project for iOS/iPadOS/macOS/tvOS/watchOS. Very soon you encounter the first bug and, in order to understand and fix it, add logs – call print() here and there. The bug was fixed and some of the logs were removed, and some were left for the future – useful, still useful.

After a couple of months of work on the project, the console in Xcode turns into a waterfall of logs. They are difficult to understand, they are impossible to navigate. Take it for granted and add some type of markets to new logs for convenience "----->" or something else like that – so they can be distinguished in an endless stream.

It works, but exactly until it stops. At this moment, you can’t stand it and clean most of the logs that you think are useless, accidentally hooking useful ones along with them. Now you have some logs that show something. What their value is is not clear.

Let’s talk about how Apple proposes to solve this problem.

console.app

Apple offers to read logs in a special application – Console.app, which is built into macOS. But if you run it and select a device with your running application, then you will see an even larger footcloth of messages: here are system logs, and application logs from other developers.

Filter only up to your application. To do this, there is a search box on the top right. For this article, I made a LogsDemo application, so that’s what I enter into the search field:

Empty. It’s because print() outputs the log directly to the Xcode console, and Console.app tries to read the logs from the log files. In order for the recording to go to these same log files, you need print() replaced by os_log(). Apple calls it part Unified Logging System.

We replace, it turns out like this:

let message = "Наше с вами сообщение, которое упадёт в логи"

// вызов os_log требует инстанс OSLog
let osLog = OSLog(subsystem: "LogsDemo", category: "") 

os_log(.debug, // говорим, что уровень лога будет 'debug'
		log: osLog, // передаём тот самый инстанс OSLog
		"%{public}@", message as! CVarArg) // передаём наше сообщение

We start the project and check: the logs fall into the Xcode console, but there are still no logs in Console.app.

log levels

Level logs .debug are not added to the log file, but immediately flies directly to the Xcode console. In order for the log to reach the console, it is enough to change its level to any other.

There are five levels in total:

public static let `default`: OSLogType
public static let info: OSLogType
public static let debug: OSLogType
public static let error: OSLogType
public static let fault: OSLogType

Let’s point out .default and check:

Some system logs are still shown – because we said in the search field to show any logs from LogsDemo. By default, this includes the logs from iOS that happened as a result of the work of our application.

Filters

Let’s refine the filter a bit. We have different options:

All possible filters and below options for their application.
All possible filters and below options for their application.

We will suit Library, Equals:

Test logs from the demo application.
Test logs from the demo application.

Finally what you need. But each time you enter the name of the application in the search and refine the filter – too lazy. It’s good that filters can be saved: there is a Save button right below the search field. Click, enter a name for the filter and it appears in the toolbar:

You can save multiple filters at once.  For example, I have live filters for network requests and for analytics inside Dodo Pizza, as well as for my pet projects.
You can save multiple filters at once. For example, I have live filters for network requests and for analytics inside Dodo Pizza, as well as for my pet projects.

It is possible even to thrust the filter only on errors. We call the context menu of the log with an error and ask to show only errors:

Each column has its own context menu.  To get items filtered by the Type field, you need to click on the Type column.
Each column has its own context menu. To get items filtered by the Type field, you need to click on the Type column.

And now we only show logs with the level .error:

Log source

Much more often, when debugging, I want to look not “only errors”, but logs “only from module N”. We are actively sawing the Dodo Pizza application into modules – we already have 62 of them. Viewing only the logs from the network is a completely normal case for us. The demo project also has a Network module, let’s filter the logs up to it. But where to get the name of the current module? And where to send it? Writing by hand sounds like a daunting task. And if you transfer a file with code between modules, then you can forget to update the transferred name.

But what if I say that the correct name can be automatically obtained without straining? It will be returned by the expression #fileID:

let fileID: StaticString = #fileID
// результат — LogsDemo/ViewController.swift

let module = URL(fileURLWithPath: self).deletingPathExtension().pathComponents[1]
// результат — LogsDemo

Now in console.app you can add a filter by Subsystem: Network and see only the logs from the module Network:

We know the module. What’s next?

  1. The file name can be obtained in the same way as the module name, directly from #fileID.

  2. The name of the function can be obtained from #function.

  3. A line from #line.

And now we glue it all into one message:

// Раньше в OSLog в поле subsystem мы подавали название приложения
// Но оно и так в любом случае пишется в логи в поле Library
// Так что мы вместо названия приложения теперь подаём название модуля
let osLog = OSLog(subsystem: module, category: "")

let fileFunction = [filename, function].joined(separator: ".")
let source = [fileFunction, line].joined(separator: ":")

let formattedMessage = [source, message].joined(separator: "\n\n")

os_log(.default,
       log: osLog,
       "%{public}@", formattedMessage) 

In Console.app like this:

Now we know in which module, in which file and on which line what happened. Well, if pledged.

What else is possible?

Whatever – os_log accepts any text message and prints it to the console.

Mistake? Please:

enum TaxCalculationError: Error {
    case invalidTaxConfig
}

let message = String(reflecting: TaxCalculationError.invalidTaxConfig)
os_log(.error,
       log: logger,
       "%{public}@", message) 

Freeze? You can also:

// логируем старт
let startMessage = "Will get profile"

// специального уровня для замеров нет, так что используем дефолтный
os_log(.default, 
       log: logger,
       "%{public}@", startMessage) 


// запоминаем во сколько мы начали
let startDate = Date()

// выполняем какой-то долгий код
let response = networkService.data(for: ProfileRequest())
let profileModel = ProfileModel(response)

// запоминаем во сколько мы закончили
let endDate = Date()

// сравниваем конечное и стартовое время 
let duration = endDate.timeInterval(since: startDate)
let durationFormatter = String(format: "%.2f", duration)

// логируем конец с продолжительностью
let endMessage = "Got profile, took \(durationFormatter)s"
os_log(.default,
       log: logger,
       "%{public}@", endMessage) 

Conclusion

Bundle os_log and Console.app is a powerful tool. You can log the network layer of your application, errors that occur at any time, as well as measure how long a particular function has been running for you and display it in text in the logs.

But to use it, you have to write a lot of accompanying code. Boilerplate, forgive me this word. It is necessary to format ordinary messages, and correctly show errors, and somehow shove measurements of the execution of functions. How to avoid this – I will tell in one of the following articles. Subscribe, like, share this article with your friends.

Similar Posts

Leave a Reply