Norway


Thinking of migrating your iOS or macOS from a bunch of NSLog or print statements to the new(ish) Logging system? Keep reading for some facts and tidbits that might surprise you, along with a few suggestions for how to make the most of your transition.

If you’re not sure why you’d want to use Unified Logging, here’s a quick run-down of some key benefits:

  1. It’s the new standard. The Unified Logging system is the biggest change to logging on Apple Platforms in years. It has all the telltale signs of something that Apple intends as the way to do logging going forward.

  2. Improve your app’s performance without sacrificing log coverage. The new logging system is designed from the ground up to limit the observer effect that logging has traditionally had on production code. You can now have it both ways: thorough log coverage and great performance.

  3. Upgrade your debugging workflow. Messages logged with the new APIs can be “tagged” with customized subsystems and categories which empowers Console.app to show or hide messages with expressive search filters. This can you oodles of time when debugging complex issues that span more than one module or process.

I could go on with other benefits, but those will become apparent as we explore the differences between Unified Logging and what it replaces.

Four Ways Unified Logging is Different Than Legacy Logging Techniques

The following is not an exhaustive list of everything that’s new or different with Unified Logging, but rather a few key differences that may have a tremendous impact on how you go about migrating away from legacy logging functions.

1: OSLog isn’t a function. It’s a data type.

You will sometimes hear folks refer colloquially to Unified Logging as “oh-ess-log”, which might send you on a goose chase through the Foundation docs for an OSLog function. There isn’t one. The true analog to NSLog is any of the various functions like os_log that are defined in <os/log.h>, most of which take an os_log_t (a.k.a. OSLog via the Swift overlay) as an argument. The OSLog type is used to associate related messages so they can participate in Console.app’s search and filter features.

2: Console.app is mandatory.

Unified Logging doesn’t serialize log messages in plain text, nor to a human-readable file format. Instead all messages are written to disk in an opaque data format that can only be read by opening a log archive (see below for how to obtain one) in Console.app. Console.app can unpack the archived messages, displaying them in a manner that is easy to search and filter. The opaqueness of the data format is a departure from logging systems you may be familiar with. It was undertaken by Apple in an effort to limit the deleterious effects that logging traditionally has on performance and disk space.

3: From Swift, you can only pass a StaticString as a log message.

The following Swift code will not compile:

let foo = "Something happened."
os_log(foo) 

// Error: Cannot convert value of type 'String' to expected argument type 'StaticString'

That’s because the Swift compiler resolves the implicit type of an otherwise unconstrained string literal to String, but the os_log function requires a StaticString. You can fix it either by giving the variable an explicit type:

let foo: StaticString = "Something happened."
os_log(foo)

or by eliminating the variable:

os_log("Something happened.")

The static string string can also be a C-style format string:

os_log("We bolster %ld husk nuts to each girdle jerry.", )

Please note that you cannot use Swift’s pleasant string interpolation when logging a message:

let count = 12
os_log("We bolster (count) husk nuts to each girdle jerry.")

// Error: Cannot convert value of type 'String' to expected argument type 'StaticString'

This is probably the most significant departure you will encounter when migrating your Swift code from NSLog to Unified Logging. Be prepared for much dirt in your git working directory as you slog your way through substituting os_log calls for each NSLog or print call.

It is possible to log a String, but only as an argument to a static format string:

let count = 12
let string = "We bolster (count) husk nuts to each girdle jerry."
os_log("%@", string)

This workaround comes with a big gotcha, as we will see next.

4: Barring exceptions, your format arguments will be <redacted>.

By default when you log a String as a format argument:

os_log("What is %@?", "threeve")

the message will be rendered like this in Console.app:

Process Message
MyApp What is <redacted>?

To reveal the full log message in production logs, you have to explicitly mark that format argument as {public}:

os_log("What is %{public}@?", "threeve")

Then the log message will appear unredacted in your production logs:

Process Message
MyApp What is threeve?

Alternatively, you can achieve the same effect on a temporary basis without the {public} scope modifier by doing either of the following before running the app:

Some argument types do not require these workarounds. Scalar values — bools, integers, etc. — will default to an implied public scope when used as format arguments. You can also mark a scalar argument as {private} if you need to ensure that the value will be redacted in production, overriding the default public scope:

os_log("My secret ID is %{private}ld.", user.secretId)

Dos & Don’ts

Here are some things I consider best practices, in no particular order:

Do: Pay attention to log levels (types).

There are five standard log types, which mostly correspond to what used to be called “levels”, that are defined by the Unified Logging system. Here they are along with brief summaries cribbed directly from the official documentation:

  • default: Use this level to capture information about things that might result in a failure.
  • info: Use this level to capture information that may be helpful, but isn’t essential, for troubleshooting errors.
  • debug: Use this level to capture information that may be useful during development or while troubleshooting a specific problem.
  • error: Use this log level to capture process-level information to report errors in the process.
  • fault: Use this level to capture system-level or multi-process information to report system errors.

the most appropriate type on a case-by-case basis, as any two given types are not treated equally by the logging system. This WWDC video has a helpful deep-dive into these differences.

Don’t: Use OSLog.default in shipping code.

You are not obligated to initialize your own OSLog instances. The OSLog.default value is available as a bare-bones alternative and is the default value for functions like os_log which require an OSLog argument. However, when you use OSLog.default, your ability to filter your log messages is limited because no values are provided for subsystem or category:

Image of a log message using the default log.  - unifiedlogging 1 - Migrating to Unified Logging, Swift Edition

When you initialize your own OSLog, you provide it with a subsystem and a category. This makes it a snap to filter the visible output in Console.app:

Image of a log message using a custom log.  - unifiedlogging 2 - Migrating to Unified Logging, Swift Edition

Do: Name your subsystems and categories consistently.

Adhere to a consistent naming convention across your application. It’s worth spending some time looking at how Apple chooses their values for these for logs emanating from their own processes as this should inform your own conventions. Here are my recommendations, which are drawn from Apple’s established patterns:

  1. Always name your subsystems using a reverse domain name style. All of Apple’s own logs have subsystems prefixed with com.apple, such as com.apple.Siri or com.apple.coredata.

  2. If your code is organized into frameworks, use the bundle ID of the calling module as the subsystem for all logs in that module, e.g. com.company.MyApp for application-level logs and com.company.MyApp.SomeFramework for framework-level logs.

  3. Do not use a reverse domain name style for a category name. Instead use a short, human-readable name like “ Service”.

  4. Choose category names that help narrow the scope of the calling code within its module or that can associate related logs that span multiple files or subsystems. For example, if you have logs that are specific to only one Authenticator class within a custom framework, you might give its logs the category name Authenticator to be used exclusively by that class. Alternatively, if you have lots of authentication-related work spanning more than one class or more than one framework, you could have them all use a category name like Authentication, which would help you see authentication activity across your entire application.

Don’t: Hide your logs behind conditionals.

Because the rendering of the logs is done after the fact by Console.app, there’s no need to filter your log messages programmatically through #if directives or other conditionals. Log everything simply and directly, using an appropriate type, and let the system take care of the .

Do: Practice gathering a sysdiagnose.

Get really good at obtaining a sysdiagnose from hardware out in the wild. Full instructions are available here, but the gist of the process is:

  • Press and hold a bunch of buttons.
  • Wait ten minutes.
  • Navigate to a screen deep inside Settings.app
  • Tap the zipped sysdiagnose and AirDrop it to your Mac (it’ll be ~300MB in size).

Once you have the sysdiagnose on your Mac, you can open the .logarchive file it contains in Console.app and see a dump of all the logs on that device. If you’ve heeded my advice on categories and subsystems, you should be able to filter down to the information you need in short order.

[record needle scratch] Hold on. Did you say I have to wait ten minutes?

Yes, it can take up to ten minutes for sysdiagnose to appear after one has been requested. Because of that delay, you don’t want to make sysdiagnoses part of a daily debugging routine. Instead, sysdiagnoses are useful in situations like this:

  • A minimally -savvy customer reports a bug in production within a few minutes of the event. Walk them through the sysdiagnose steps and find a way for them to send it to you.

  • You or someone on your team encounters a bug while away-from-keyboard. Trigger a sysdiagnose immediately, and then grab it from the device once it’s back in the office.

Don’t: Force all format arguments to a public scope.

If you are used to reading all your log output in plain text, it can be a jolt to have to deal with the Unified Logging system’s private-by-default policy. Resist the temptation to force all your format arguments to a {public} scope. Not only does that risk disclosing your customers’ private information (say, if they send a sysdiagnose to another company), but it also risks exposing your company’s secrets. It’s not difficult to imagine a scenario where an error log accidentally reveals your OAuth credentials in plain text in production logs.

Do: Watch these WWDC videos.

Both of these are required material for anyone interested in Unified Logging:

Departing Note

Image of a log message thanking the reader.  - unifiedlogging thanks - Migrating to Unified Logging, Swift Edition



Source link

LEAVE A REPLY

Please enter your comment!
Please enter your name here