Convenient Logging in Swift
Setup Willow for a great logging experience in iOS Applications
When features won’t work as expected debugging may become hard. Finding the problem in large projects can be really time-consuming and in my experience, it’s often something as simple as a failing guard statement.
Logging makes the application flow traceable so you always know what’s going on. This is beneficial in order to
better understand the flow of an application and
finding bugs or the cause of unusual behavior much faster
Also, debuggers are only useful if they’re present when something bad happens.
Logging with Print-Statements 😈
I’ve seen this so many times before. There’re many problems with print-statements.
Problem #1: Chaos
It’s hard to verify where they come from. And it’s not clear if they want to tell us something important or if just someone forgot to remove the line before pushing to vcs. They also have no context. Imagine a large application with UI-actions, networking, data-processing, … And everywhere print statements. You can’t turn particular parts off and get a bunch of uninteresting information.
Problem #2: Performance
Print-Statements are performed synchronously so they’re blocking the main thread. This will be especially problematic when printing during UI animations. I’ve seen apps got very jerkily due to this problem.
So let’s avoid these problems by implementing a nice logging system.
Logging with Willow by Nike Engineering ✔
I choose Willow because it’s a lightweight but yet powerful logging library. One of my favorite features is the manipulation of messages by implementing custom log-modifiers. I 😍💕❤️ emojis so this was really fun for me. Unfortunately, Xcode doesn’t support colored output so I use them to bring more visual context into my log messages.
Implementing Willow
You can use CocoaPods, Carthage or Swift Package Manger. Check out the installation instructions here https://github.com/Nike-Inc/Willow#installation.
Create the configuration for debugging
We will now implement a logger for debug-builds. We will configure:
- A logger which prints synchronous messages (As I mentioned above, this will block the main thread! ⚠️)
- Create an emoji 🤩 LogModifier to create more visual context
Log-Levels
It’s important to know if a log-message is relevant or not. One message could be something informative “successfully created a user with ID=1337” but also something serve as “🚨Fatal Error occurred: App deleted all data accidentally“. So you have to choose wise which “Log-Level” your message belongs to. This also allows us filtering. Maybe you just want to display serve problems.
Willow comes with these default log-levels:
debug- Highly detailed information of a context
info- Summary information of a context
event- User driven interactions such as button taps, view transitions, selecting a cell
warn- An error occurred but it is recoverable
error- A non-recoverable error occurred
Let’s configure our project to create an awesome logging experience.
Step #1: Build a simple logger
First, we build a simple function which builds the willow-logger for us. We’ll be using a ConsoleWriter. It’s basically like the traditional print statement so it blocks the thread you’re logging to. This will have some performance disadvantages so I only use this configuration for debugging.
Before you can start logging, you have to call the configure() function at your App start. Call the function in the application:didFinishLaunchingWithOptions method in your AppDelegate.
Now your logging is set up. Try it out by creating a simple info-message.
willowLogger?.infoMessage("Hello World!")
Let’s bring some fun into logging by implementing a Log-Modifier.
Step #2: Custom Log-Modifier
Log-Modifiers take your log-messages and format them in order to provide more detailed information. I want to use emojis to display the log-level the message was sent with.
Create a new struct and inherit the “LogModifier” protocol by Willow. You’re forced to implement the “modifyMessage” function. The function will be called every time you send a log message.
You can use my implementation or create your own. In my case, I added a “name” attribute to differentiate multiple logger-implementations later (I use multiple loggers for different parts of my app e. g. WebView, UI, Networking, …) and of course emojis!
Instantiate the EmojiModifier in your LoggingConfiguration.swift and pass it to the ConsoleWriter:
Restart your app and you’ll see wonderful emojis:
willowLogger?.infoMessage("Hello World!")willowLogger?.errorMessage("App started with 1337 bugs.")
Step #3: Timestamp Modifier
I don’t log time in my debug configuration but it sometimes makes sense (e. g. performance, comparing concurrent events). The TimestampModifier is also a LogModifier like the one we created it in the last step. Willow allows us to process our message through multiple modifiers so we can just add it to our configuration.
let consoleWriter = ConsoleWriter(modifiers: [emojiModifier, TimestampModifier()])This will produce following output:
Step #4: File name and line numbers with a proxy
One big problem with basic log messages is it’s hard to find out where they come from. So I’m going to print the file, the function and the line number to make my life easier.
Unfortunately, I haven’t found a solution to this information in willow yet. Let me know if there’s already a solution.
Currently, I use a Logging-Proxy. It’s a struct which acts as my primary logger and proxies the log-message with the information forward to willow.
You can get this information using #file, #function or #line literals. I use them as default parameters so I don’t have to pass them around.
If you use my configuration, use logger instead of willowLogger and your output changes to:
The thread-block performance problem
Right now we block the thread like prints statements. It’s ok for finding bugs but disastrous for release. So we create a different log-configuration for release which won’t block any threads and uses a performant logging technology.
Step #5: Create a DEBUG flag 🚩
We have to check if our app is build for debugging or release. In order to do this we need to pass a compiler-flag.
Click on your project file in Xcode and choose the „Build-Settings“ tab. Now search for „Compilation Conditions“. You can now set custom compiler-flags for specific build-targets. Set the value „DEBUG“ in the debug-section for „Any architecture | Any SDK“.
OS_log
OS_log is the logging API in MacOS, iOS, WatchOS and tvOS (More about this topic: https://developer.apple.com/documentation/os/logging). I’ll use this as my release logging technology.
BTW: I used the ConsoleWriter for debugging because I disabled os_log output via OS_ACTIVITY_MODE=disable because it produces lot’s of uninteresting output.
Step #6: Create a release logger configuration
Now I create a logging configuration for release. Willow offers us a OSLogWriter. So I choose this one instead of the ConsoleWriter we used for debugging. This time I write asynchronously to os_log.
We have to set a category and a subsystem. We can identify our log messages later using the unique subsystem identifier.
Category is the part of your app. If you have multiple loggers this might be WebView, UI, Networking, … This allows us to filter our logs later and only display information which is important to us. The name of my logger represents the os_log category.
Let’s try it out. Edit your scheme -> switch to Build Configuration “Release” and uncheck “Debug executable”.
Run your app and you’ll see your os_log output.
But there’s a better way to display your log messages: Console.app!
Step #7: Display your log messages in Console
Open Console and choose your device from the left sidebar.
Now search with your subsystem identifier you set in the release logging configuration. Click on “Any” and choose “Subsystem” as filter.
Let’s run your app on a device:
Now our log message is displayed in the Console.app. Press Command + S to save the filter for later usage. Console brings tons of other filtering options which is great for large apps and multiple logging categories.
If you want to learn more about Console and os_logging check out this WWDC `16 talk https://developer.apple.com/videos/play/wwdc2016/721/
Logging to os_log in release has one great benefit: If someone experience problems in the TestFlight app, you can connect their device to your Mac and get deep insights of what’s going wrong using the Console.app. This will safe me a hudge amount of debugging when the apps are working everywhere instead of my product owners device 😕
Conclusion
A well-thought logging setup saves you hours of debugging and gives you an overview of what’s happening in your app. Be careful of performance problems in release configurations. Slowing down our apps would be the worst case.
You can find the full configuration here: https://github.com/jbrunhuber/swift-willow-config
Do you have questions? Feel free to contact me on Twitter!
