Logging Messages

For novice developers, the first line of defense against bugs is to just write messages to the console to see what’s going on. We’ve been doing this with the print function way back in ​for Loops​, and have used it occasionally throughout the book, usually as a placeholder to make sure our app reached the new code we were writing.

The gist of print is that it will print a message to the console that only we will see. (Foundation also has an NSLog function that provides a timestamp and the process name of the app.) It might seem counterintuitive to create output that only we will see, but it is vitally important to have some means of verifying what is happening in our program.

Let’s put ourselves in a situation where we might want to use print to find our way out. For example, let’s say we made a simple mistake when writing our episode parser and thought the title tag was actually called name instead.

That would be a simple mistake, but the results would be devastating, as we’ll see. Open PodcastEpisodeParser.swift and change both instances of "title" to "name" (they’re in parser(didStartElement:qualifiedName:attributes:) and parser(didEndElement:qualifiedName:)). Run the app, and notice that all the episodes are now missing their titles, as seen in the figure.

If we didn’t know the root cause was the wrong element name, we’d have to think of reasons this might be happening. Since we have table rows and some of the episode metadata, there are a bunch of things we can rule out—fetching the URL and parsing the feed must be working to some degree. We might correctly guess that we’re parsing the XML incorrectly, but we might also surmise that the label is hidden or transparent in the storyboard, that the label’s IBOutlet is not connected, that tableView(cellForRowAt:) is failing to set its text, and so on.

We can mentally walk along the path our code takes from launch to the updated table, as shown in the following figure, in order to figure out where the problem might be, but we can’t verify it without running some kind of test.

As you can see from the figure, there are at least four points in the operation where something could have gone wrong—maybe more, when we consider that some of these steps have multiple steps within them, or that the label could be wrong in the storyboard (it could be hidden, or the same color as the background, or misplaced, etc.)

By setting up feedback for every step in the process, we can now observe at what point in this chain things break down. By throwing down a bunch of prints, we can at least focus our search—if we have a log statement atop parser(didStartElement:qualifiedName:attributes:) that logs the elementName, we’ll realize that we never see name, and hopefully figure out that what we wanted was title.