ylliX - Online Advertising Network
Xcode breakpoint action
iOS Development

Better logging with Emoji

Written by News One


Apple’s developer tools provide a rich variety of debugging aids. Sometimes though, it’s useful to do things the old fashioned way. With debugging, this often means just printing out data while your code runs, and then looking through the results to see what’s going on.

Some scenarios where printing debug data helps include:

  • When you need to check on something that happens a lot.
  • When the mental context switching between using your app and using the debugger gets to be too much.
  • When short timeouts for actions mean that a round-trip to the debugger interferes when what you want to test. If something happens automatically after a few seconds, can you get to Xcode and back in time?

Xcode breakpoint actions

If you’re not using a lot of debug printing, Xcode’s breakpoint actions are a good choice. Add a breakpoint and give it a “log message” action that prints something useful. Then make sure the breakpoint automatically continues, so that the code prints the message but doesn’t actually stop on the line.

Xcode breakpoint action

This is really nice because you can add these anywhere without putting debug-only print statements in your code. There’s zero chance of these ending up in production code, since they only exist in Xcode.

There are a couple of drawbacks. One is that you need to use the Xcode UI to add them, which gets tedious if you need more than a few. You can’t copy and paste them– you need to go through a bunch of mouse actions for each one. Another is that Xcode still has the annoying habit that, if you delete a line of code, a breakpoint on that line or on an adjacent line will sometimes disappear. There goes your print statement!

Improving on “print” for debugging

The obvious alternative in Swift is to use print wherever you need to know what’s happening. That’s easy and common, so if it works for you, go right ahead.

I have a wrapper I’ve used that makes it a little more useful when debugging. Often when I want to print, all I really want to know is “hey, you reached this line of code”. The log message needs to tell me where it is, but nothing else is necessary.

I could do something like this but it gets to be almost as tedious as using breakpoint actions, since each one needs to be customized:

print("Made it to DetailViewController's viewDidLoad")

Simple, yes, but every one is different, so I’d have to type out each one.

My first pass at this makes use of Swift’s #file, #function, and #line to fill in the details of where the message occurs. There’s an optional extra message to add relevant information:

func logMilestone(_ message: String? = nil, file: String = #file, function: String = #function, line: Int = #line) -> Void {
    if let message = message {
        print("Milestone: \((file as NSString).lastPathComponent):\(line) \(function): \(message)")
    } else {
        print("Milestone: \((file as NSString).lastPathComponent):\(line) \(function)")
    }
}

These hashtag-like values provide default values for function arguments. Since all arguments are either optional or have default values, I can call this message with no arguments. Dropping this in various places in code:

Produces something like this:

Milestone: AppDelegate.swift:19 application(_:didFinishLaunchingWithOptions:)
Milestone: SceneDelegate.swift:20 scene(_:willConnectTo:options:)
Milestone: SplitViewController.swift:14 viewDidLoad()
Milestone: SceneDelegate.swift:61 splitViewController(_:collapseSecondary:onto:)
Milestone: BaseCollectionViewController.swift:40 viewDidLoad()
Milestone: BaseCollectionViewController.swift:15 collectionView
Milestone: BaseCollectionViewController.swift:26 layout
Milestone: SymbolsCollectionViewController.swift:63 viewDidLoad()
Milestone: SymbolsCollectionViewController.swift:13 searchController
Milestone: SymbolsCollectionViewController.swift:37 symbols

For each message I get the filename, line number, and function where logMilestone was called. It even works for computed properties, showing the property name instead of the function.

I include the word Milestone because it makes it easy to use Xcode’s console filtering so that I see only these messages and nothing else.

Xcode console filter

Using Emoji to improve readability

So that’s nice, but it can still be awkward if you have a lot of log messages. It would be handy if there were some visual cue about what file a message came from. You might see a message from one file and want to find the next one from that file, even if there are a bunch of other messages in between. What if each filename had a unique Emoji?

I do this by getting an integer hash of the filename, and then using that integer to select an Emoji from an array. That ends up looking like this.

func logMilestone(_ message: String? = nil, file: String = #file, function: String = #function, line: Int = #line) -> Void {
    let logEmojis = ["😀","😎","😱","😈","👺","👽","👾","🤖","🎃","👍","👁","🧠","🎒","🧤","🐶","🐱","🐭","🐹","🦊","🐻","🐨","🐵","🦄","🦋","🌈","🔥","💥","⭐️","🍉","🥝","🌽","🍔","🍿","🎹","🎁","❤️","🧡","💛","💚","💙","💜","🔔"]
    let logEmoji = logEmojis[abs(file.hashValue % logEmojis.count)]
    if let message = message {
        print("Milestone: \(logEmoji) \((file as NSString).lastPathComponent):\(line) \(function): \(message)")
    } else {
        print("Milestone: \(logEmoji) \((file as NSString).lastPathComponent):\(line) \(function)")
    }
}

The filename’s hash value selects an entry from logEmojis, and this Emoji becomes part of the log message. The log messages from earlier end up looking like this:

Milestone: 👺 AppDelegate.swift:19 application(_:didFinishLaunchingWithOptions:)
Milestone: 💚 SceneDelegate.swift:20 scene(_:willConnectTo:options:)
Milestone: 👾 SplitViewController.swift:14 viewDidLoad()
Milestone: 💚 SceneDelegate.swift:61 splitViewController(_:collapseSecondary:onto:)
Milestone: 🤖 BaseCollectionViewController.swift:40 viewDidLoad()
Milestone: 🤖 BaseCollectionViewController.swift:15 collectionView
Milestone: 🤖 BaseCollectionViewController.swift:26 layout
Milestone: 🐵 SymbolsCollectionViewController.swift:63 viewDidLoad()
Milestone: 🐵 SymbolsCollectionViewController.swift:13 searchController
Milestone: 🐵 SymbolsCollectionViewController.swift:37 symbols

If I want to know what’s going on in BaseCollectionViewController.swift, I can visually scan (or have Xcode filter) for the 🤖 Emoji.

The logEmojis array is somewhat arbitrary. I wanted a few dozen entries to reduce the chance of collisions where more than one file would use the same Emoji. I chose them mostly with the goal of making them visually distinct, avoiding Emoji with similar color and shape to others in the list.

One minor annoyance is that since hashValue is randomized, each file uses a different Emoji every time you run the app. It might be possible to fix that with a custom non-random hash function but I haven’t taken it that far. If you have an idea for that, I’d love to hear it.

Fine tuning

There are a few other adjustments that can be useful.

Time stamps and thread info

If you replace print in the function body with NSLog, you’ll get both a time stamp and a thread ID. If timing is important or if you’re working on more than one thread, this can be really handy. If not though, it’s just noise.

2020-01-13 16:59:16.349681-0700 SF Viewer[71421:13996033] Milestone: 🎹 AppDelegate.swift:19 application(_:didFinishLaunchingWithOptions:)
2020-01-13 16:59:16.452943-0700 SF Viewer[71421:13996033] Milestone: 😱 SceneDelegate.swift:20 scene(_:willConnectTo:options:)
2020-01-13 16:59:16.466323-0700 SF Viewer[71421:13996033] Milestone: 🔥 SplitViewController.swift:14 viewDidLoad()
2020-01-13 16:59:16.485690-0700 SF Viewer[71421:13996033] Milestone: 😱 SceneDelegate.swift:61 splitViewController(_:collapseSecondary:onto:)
2020-01-13 16:59:16.534898-0700 SF Viewer[71421:13996033] Milestone: 🦊 BaseCollectionViewController.swift:40 viewDidLoad()
2020-01-13 16:59:16.535238-0700 SF Viewer[71421:13996033] Milestone: 🦊 BaseCollectionViewController.swift:15 collectionView
2020-01-13 16:59:16.535423-0700 SF Viewer[71421:13996033] Milestone: 🦊 BaseCollectionViewController.swift:26 layout
2020-01-13 16:59:16.540553-0700 SF Viewer[71421:13996033] Milestone: 🤖 SymbolsCollectionViewController.swift:63 viewDidLoad()
2020-01-13 16:59:16.541802-0700 SF Viewer[71421:13996033] Milestone: 🤖 SymbolsCollectionViewController.swift:13 searchController
2020-01-13 16:59:16.623701-0700 SF Viewer[71421:13996033] Milestone: 🤖 SymbolsCollectionViewController.swift:37 symbols
2020-01-13 16:59:16.624456-0700 SF Viewer[71421:13996033] Milestone: 😱 Symbols.swift:102 readCSV(_:)
2020-01-13 16:59:16.627482-0700 SF Viewer[71421:13996033] Milestone: 😱 Symbols.swift:81 getFont(for:): Getting font for weight UIImageSymbolWeight

That’s a lot of extra text on every log message. Sometimes though, you really need that information.

Logging errors

I like to include a second version of the function that wraps the one above, as a convenience when I want to log a Swift Error:

func logMilestone(_ error: Error, file: String = #file, function: String = #function, line: Int = #line) -> Void {
    logMilestone(error.localizedDescription, file: file, function: function, line: line)
}

It’s simple but it means I can just logMilestone(error) and have it work.

Keeping logs out of production code

Of course I don’t want any of this leaking through to production code. Fortunately, Xcode adds a DEBUG compiler flag to new projects (and it’s easy to add one if you don’t have it) which can easily turn logMilestone into a no-op in production builds. Just add a check inside the function, like this:

func logMilestone(_ message: String? = nil, file: String = #file, function: String = #function, line: Int = #line) -> Void {
#if DEBUG
    // Function body goes here
#endif
}

Final notes

Update: This post was featured in iOS Dev Weekly #441. Thanks again, Dave!



Source link

Leave a Reply

Your email address will not be published. Required fields are marked *