Why I think log messages are a powerful tool

  • Hey guys, I was curious what your thoughts are on logging. Over the past couple of years, I’ve found logging to be the most powerful tool in my toolbox. I’ve used http://log4javascript.org/ , then winston ( https://github.com/flatiron/winston ), but felt like they were lacking.

    I formalized the concepts I’ve followed into a library called Bragi. Basically, it’s an improved console.log with namespaces, filtering (allowing you to leave in calls to bragi.log() without having them be actually logged), colors, configurable outputs (logging to console or to a file or to a remote host, etc.), and stores structured data for each log message (so you can pipe logs to graylog, kibana, etc. to have complete visibility into what your code is doing for any user). This version is for NodeJS, but next week I’ll release the browser version.

    I’m a fan of unit tests, but not a huge proponent like I was 5 or 6 years ago. They’re a tool, and can often be more detrimental than beneficial (especially when you don’t know yet what you’re building). I wouldn’t write an untested API, but like a previous podcast discussed, it’s can be harder to write unit tests for gamedev. It’s possible, and it’s been incredibly useful for me as I’m building my game, but I find myself writing more integration tests vs. unit tests (e.g., I have a combat system that is based on timers and it’s far more efficient for me to write a series of tests that validate new spells work the right way, as I can mock time deltas and run it immediately vs. having to load the game and manually test things - but these veer more towards integration tests).

    As helpful as unit tests are, they only really can validate that your code is working. When developing, I’ve found logging to be an incredibly powerful tool that helps speed up my development time. In production, I leave logs to monitor that code is working for users. Breakpoints are great, and I use logging to inform me where to set them, but it’s very powerful to log everything, leave the logs in the code, and filter out logs that aren’t needed. I’ve been following this idea for the past couple years and it’s allowed my team and me to write and ship code faster. Also, if you leave log statements in code, when a new developer looks at code (or you look again after two months when you’ve lost context), they can immediately see the entire flow of execution without needing to know where to set breakpoints and whatnot. Calls to loggerLibrary.log() also act as comments. For me, logging has been so helpful for both app development and game development. It helps manage complexity, see state, and can provide strong visual cues of what’s going on in your code. There is very little overhead in keeps logs around in code and just filtering output (I had all logs turned on, piping to remote hosts for http://labs.five.com - our peak was 12k/users a second, in total over 200million profiles created - logs helped manage all this and had no impact on performance)

    Colors and symbols are also very useful, and I’ve found that including them makes spotting certain messages very easy. If all error messages have a red background, it immediately jumps out - your brain doesn’t need to read and process anything.

    I wrote a post describing more of why I think logging is the most underutilized but powerful tool. The library itself is on github, and the post that describes the library is here.

    Here’s a preview image of it in action: Bragi Logging

    I’m curious what your thoughts on logging are and the extent to which you guys use logging in your own projects.

  • LDG

    Very cool, thanks for sharing!

    I agree that logging is a powerful tool and one that we use quite a bit during our game development. I’d like to make this more developed as it would really help us debug player issues in the wild if they could send us a log. For now, we mostly use the log messages as reminders, “hey, you did something you weren’t supposed to do!” or “hey, something is not quite right here”.

    Interesting point about logs acting as comments as well. I hadn’t thought of that before, but it makes sense. I try to stick to the conventional wisdom that comments shouldn’t repeat the code, instead they should clarify why things are done a certain way.

    I’ve always been luke warm on unit testing (especially so for game dev), so logging is definitely important for us.

    Also, as a big fan of Norse mythology naming conventions, I approve of Bragi. :D

  • Norse mythology ftw! Thanks for checking it out. It’s great hearing your perspective on it, and that it’s something you use too.

    Logging isn’t as widespread as I’d expect it to be given how beneficial I’ve found it to be for me. It seems to be one of those things that a lot of developers do without really talking about it. Unlike unit testing. It’s crazy to me how some developers adhere so religiously to unit tests, yet they can sometimes cause more harm than good (I lived in the south for most my life before coming to the bay area, and man - even the most evangelical churches don’t hold a candle to the fervor of belief that some TDD proponents have)

    I agree with your philosophy on comments. Ideally, I prefer small functions with a comment at the beginning (a sentence or two) describing what the function does, and descriptive variable names in the code. Logs can’t replace all comments of course, but for me, the cool part is that log() calls have a dual nature - they can implicitly provide descriptions (and as act as comments), but they also explicitly log stuff, providing you with data into your code.

    It sounds a little strange, but I liter my code with log messages. When a function is called, when a function returns, when an async function is called / returned, when significant logic happens, or anywhere I want to be able to poke at and capture state…I don’t discriminate. It might seem like a lot of overhead, but it’s a small price to pay for a ton of rich data. One of the many upsides is that you can pipe all the logs that lead up to an error message; sometimes the error message itself might not provide sufficient data to diagnose the cause of the error.

    I could ramble for hours (er, maybe I already have;) ) about why I think logging is so great, but I think the core of it, for me, is that logs (especially structured data, like Bragi provides) provide data. With that data comes increased visibility; both for development and production. Logging also aides in code’s communication. A new developer (or myself after I haven’t looked at my code in a few months) can enable all logs and see exactly what the code is doing - quicker than looking through files, settings breakpoints, reading docs, etc. Programming is a hard, abstract complex task. Logging doesn’t really reduce that complexity, but out of all the techniques I’ve tried, I’ve found logging to be the best at communicating the complexity and providing visibility. With structured logs, you can answer nearly any question you have about what your code is doing or how it’s being used.

    Thanks again for checking it out (I’ll be releasing the web browser version next week). if there’s anything you feel that can make logging (in general) a better tool - or if there are some shortcomings you’ve found - I’ve love to hear it

Log in to reply