Jaa

A little typo bug in a log file

  • Artikkeli

I saw this bug much like this get filed last week:

Error condition:

Open one of our debugging logs and see this:
CEntity found as: <null>, replcaed with

Expected behavior:

Spell "replcaed" as "replaced"

The developer who had to fix this bug had a little chuckle, I'm sure. This log is a log file that we use internally to help diagnose problems. Between the tester who filed the bug and the developer who fixed it, we probably can identify nearly 100% of the users that would ever see this.

But not 100%, and that is key. Imagine you had to track down a bug in which a Centity object, whatever that is, is null, and its ID had to be replaced because there was a bug in the replace routine. The only clue you had as to when this happened was this log. Also imagine the log file was several hundred megabytes or so. If you tried to search for "null" you might get 5000 hits, only 4 of which deal with this particular line in the log. "CEnitity" can also be imagined to be logged 1000s of times, again only 4 for this log entry in which you are interested. The only other key word here is "replaced."

Now, unless you had looked through the code, you would not know the word was spelled wrong. If you searched for "replaced" you would not find this line. You could then easily suspect that the logging routine was broken, or the error causing the original bug was not related to CEntity being null, or any other number of dead ends.

So that's the real reason to fix this silly little typo - it can make parsing the logs a little easier. The contrarian in me says that if I knew the word was spelled incorrectly, I could use that knowledge to more quickly parse through the log. Of course, I could then stop logging text completely and just log error codes or guids, but that won't scale well at all.

It's little typos like this that can make testing easy or hard. I can also imaging a scenario in which you automate the tool to look for this error based on the typo and then in a year or two someone "fixes" the spelling error. At that point, the tool would be broken and it might take a while to notice, especially if you were gone when the fix was made.

I thought you may be interested in a little behind the scenes bug we fixed this last week. The devil, as they say, is in the details. Oh, and I got an idea for a blog article from it :)

Questions, comments, concerns and criticisms always welcome,
John

Comments

  • Anonymous
    April 23, 2012
    Why did this bug get passed off to a developer to be fixed? Since this sounds like a very simple (probably hard-coded) string change, why didn't the tester who found the bug track it down in the codebase themselves instead of filing the bug and making someone else do it? I would have probably just dug into the codebase and proposed the fix; on the other hand, this bug would most likely have been marked Won't Fix before it got to a developer on my team; and I'm one of the SDETs in my group most likely to dive into product code.

  • Anonymous
    April 23, 2012
    Good question. The tester who filed it was knee deep in debugging - which is how he noticed this in the first place- and it was quicker to hand it off to dev at that point.  Also, the developer was working with the logging routine anyway, so letting him make this change as part of his next check in is just as fast.  Plus, we need to train devs to prevent this silliness from happening in the first place so making the dev fix it just reinforces good spelling habits :)