Bug-hunting in Consolation and Woodpile: success in obscurity

This post isn’t about using my log browsers Consolation and Woodpile to hunt bugs, but about how I found a fairly obscure bug in code I have been using to convert JSON data. It may seem obscure, but it was bad enough to cause a crash.

If you don’t want to read the story, here are the new fixed versions:
of Consolation 3 consolation3b11a
and Woodpile woodpile10b6
and they’re both available in Downloads above.

Finding the bug

I was using Consolation yesterday to explore keychains again, and wanted to capture full information from a log excerpt. I therefore enabled a style which wrote all the log entry fields, and Consolation 3 immediately crashed on me. Remembering what I had been doing, I then tried to work out what it was in that particular style which caused the crash.

By a process of elimination, I discovered that including the traceID field (field 7) from the log caused the crash much of the time, but not always. I then generated raw JSON output and reviewed what was being written in that field. Although it is a numeric (integer) field and not a string, the numbers there were looking very large, so I suspected that this was the result of numeric overflow.

The bug affects all earlier versions of Consolation 3 and Woodpile, which feature styled log output, where you specify which log fields are displayed and what colour they are shown in. Here, it only occurs if you include the traceID field (field 7) in your style. It also affects Consolation 3’s conversion to CSV text, using the Export button. In both cases, a crash occurs if and when the app encounters a traceID value which is larger than a normal integer in size.

The cause

When processing a JSON-formatted log excerpt, I first turn it from raw data into an array of dictionaries, using
let json = try? JSONSerialization.jsonObject(with: data, options: [])
theJSONDictionaries = (json as? NSArray)!

then iterate through the array, converting it one line (= dictionary) at a time.

Each line/dictionary is then cast as an NSDictionary, and I look up the values for the keys that I need to access – in this case, for traceID:
let json2 = jsonObj as? NSDictionary
let json3 = json2?.object(forKey: theKeys[theIndex])

json3 can, in this case, be a String or an integer. Depending on the key, I know which it is, and for traceID it is an integer. I was therefore obtaining it in a string representation by
let json5 = json3 as! Int
json4 = json5.description

Until yesterday, that had been robust, but I was clearly encountering traceID values which couldn’t be cast as Integers. Looking at the limited debug information which Xcode was offering, it dropped me the clue that the JSON value was actually an NSNumber – not a numeric type which I would have thought to use.

So I changed the cast to read
let json5 = json3 as! NSNumber
json4 = json5.description

and it now seems robust again.

Lesson for Swift users

When reading a JSON object, it is worth remembering that strings will be accessible as Strings, and that numbers given without double quotes in the JSON source will end up as NSNumbers. I had got away with assuming that they would always be Ints, and then been caught out when some weren’t.