{"id":39,"date":"2011-04-30T10:40:54","date_gmt":"2011-04-30T14:40:54","guid":{"rendered":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/?p=39"},"modified":"2011-10-02T00:01:13","modified_gmt":"2011-10-02T04:01:13","slug":"to-log-or-not-to-log","status":"publish","type":"post","link":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/2011\/04\/30\/to-log-or-not-to-log\/","title":{"rendered":"To log or not to log"},"content":{"rendered":"<p>Well I&#8217;ve finally gotten some time to get back into a bit of programming.\u00a0 I&#8217;ve been beating myself up cause I just haven&#8217;t had time with school, but now I&#8217;ve got a little bit of downtime so I plan on taking advantage of it.<br \/>\nSadly, it had been so long since I had looked at any code that I had to do a quick review of what was there and where I left off.\u00a0 Ahh yes, gestures!\u00a0 Well I hit play and started to try out what was there \u2026 hmm gestures don&#8217;t work.\u00a0 So next step is to start printing out some debug data of where I&#8217;m tapping.\u00a0 But wait, I don&#8217;t really have any debugging utilities yet.\u00a0 Well I think I found my project for tonight.<br \/>\n<!--more--><\/p>\n<p>Since I love design, and I think the majority of a program\/game should be all done in design work and then code, we&#8217;ll start out with defining the requirements for our debugger.<\/p>\n<p>&nbsp;<\/p>\n<p><strong>Requirements<\/strong><\/p>\n<p><strong>1. multiple levels of debug messages<\/strong><br \/>\nI find this important so that you can change the amount of debug output for different uses.\u00a0 Different detail levels means you won&#8217;t be overwhelmed by debug output when things start up if you just want to see error messages.<\/p>\n<p>Error, Warning, Info, Basic, Detailed, and Verbose (in that order) should be good levels.<br \/>\nErrors should questionably never be turned off.<\/p>\n<p><strong>2. multiple debug sections<\/strong><br \/>\nUsing different loggers for different sections or components of your project means you can change the detail levels of different sections to limit the amount of debug data to only that which is relevant.<br \/>\nThe number of sections and names should be left to the implementer.<\/p>\n<p><strong>3. change debug levels for different sections on the fly<\/strong><br \/>\nWe don&#8217;t want to be limited to using the settings we compiled in for a one time use.\u00a0 So this will give us the freedom of maybe making a debug button later and changing the debug output when we click on it.<br \/>\nAs well we want to be able to change the levels on the fly so we can even turn &#8216;on\/off&#8217; certain pieces of sections when testing something specific.\u00a0 This is more of an immediate debug feature and is compiled in when testing.\u00a0 But here&#8217;s a good example.\u00a0 If you have a tree of objects (like a SAX parser) and you&#8217;ve properly labeled everything with a &#8220;MY_SAX_PARSER&#8221; id, then you could see tons of output for every item in the tree, except we only want verbose info about the player data in the tree!\u00a0 Well now you can add in a little piece of specific code to say if (element.name==&#8221;character&#8221;) logger.level=verbose.\u00a0 And like-wise to turn it off in the end tag.<\/p>\n<p><strong>4. in release, compile away debug messages<\/strong><br \/>\nI&#8217;m usually very focused on the low level performance of things, so any code that doesn&#8217;t need to be there is just wasting time.\u00a0 This is arguable actually, cause some debug messages might actually be important for catching bugs when your game is in the wild.\u00a0 And you have the ability to call home and send a crash log then why not?\u00a0 As well the cost of checking if debug messages should be printed out, and whatever other logic you have going on here is probably minimal in comparison to other things in the system.\u00a0 You should always profile things first so you don&#8217;t waste your time!\u00a0 Still, I would like the ability to do this for the future for more of the low level code.\u00a0 If you&#8217;ve got a lot of verbose messages in your rendering code it can add up.\u00a0 So if I can do a little planning now in order to quickly eliminate things later then bonus! (Key words here are &#8220;little planning&#8221;, otherwise even this is probably not worth it)<\/p>\n<p>I think that should be enough for requirements.\u00a0 There&#8217;s always more that could be added but this is good enough for now.<br \/>\n<strong> <\/strong><\/p>\n<p>&nbsp;<\/p>\n<p><strong>Usage<\/strong><\/p>\n<p>Before you get to coding you should write out a couple lines of code for how you want to use your new logger.\u00a0 You&#8217;d be surprised how many rules get placed on your design based on usage patterns.\u00a0 Here&#8217;s a couple of the quick ways I&#8217;d like to use things.<\/p>\n<p><code>Logger logger = Logger.get(\"SECT_NAME\");<br \/>\nlogger.debug(\"msg\", \u2026);<br \/>\nlogger.info(\"msg\", \u2026);<br \/>\nlogger.error(\"msg\", \u2026);<\/code><\/p>\n<p>logger.log(dbgLvl, &#8220;msg&#8221;, \u2026);<\/p>\n<p>logger.setLevel(Logger::VERBOSE);\u00a0\u00a0\u00a0 \/\/sets the visible debug messages to verbose and above<\/p>\n<p>Logger.setLevel(&#8220;SECT_NAME&#8221;, Logger::INFO);<br \/>\nLogger.setAllLevels(Logger::ERROR);<\/p>\n<p>I think there&#8217;s one very important debug feature missing from all of the log methods.\u00a0 The line number and file.\u00a0 Problem is you need to use preprocessor definitions for this so it doesn&#8217;t look quite as nice (but then again it may help your debug code stand out).\u00a0 So these logs turn into something more like<\/p>\n<p><code>#define LOGGER_DEBUG(msg, \u2026) logger.debug(__FILE__, __LINE__, msg, __VA_ARGS__);<br \/>\n<\/code><br \/>\nWait, that locks you into using that one name for a logger though.\u00a0 How about<\/p>\n<p><code>#define LOGGER_DEBUG(myLogger, msg, \u2026) myLogger.debug(__FILE__, __LINE__, msg, __VA_ARGS__);<br \/>\n<\/code><br \/>\nThat&#8217;s a little better.\u00a0 And I think that&#8217;s a worthwhile trade off in code style for those hardcore OOP people.<br \/>\nI think the biggest implication of that&#8217;s been forced here is the fact that there&#8217;s no pointers.\u00a0 I do not want to return a new object each time cause that would be bad.\u00a0 The copy ctor used here isn&#8217;t much better, but that&#8217;s why you make sure Logger is a POD (although returning a pointer would be fine too as long as you&#8217;re not calling new and\/or requiring the user to delete the logger).<\/p>\n<p>&nbsp;<\/p>\n<p><strong>Things for the future<\/strong>.<br \/>\n<strong>1. multithreaded<\/strong><br \/>\nWe should always be aware of this nowadays really.\u00a0 But there are good ways and bad ways to do multithreaded stuff that can bring you to your knees in terms of performance.\u00a0 Lockless algorithms are very important here, but I&#8217;ll leave that to you.<\/p>\n<p><strong>2. use MVC<\/strong><br \/>\nI would definitely like to use the Model\/View\/Controller pattern because the console may not always be the best way to debug things.\u00a0 Say you&#8217;re over at Joe&#8217;s house showing off your cool new game, but then you come across a repeatable glitch.\u00a0 Well there&#8217;s no gdb console anywhere close, but you can pull up the hidden visual debug settings that will give you a console view overlay in game.\u00a0 In fact, if you think about it a little more a remote web server could be another view.\u00a0 This gives an awesome way of remotely logging the data and plugs into the same design!\u00a0 So is all of this worth it?\u00a0 Hell yes!\u00a0 You can never have too much debugging! (as long as you have a way of limiting\/filtering that data of course).\u00a0 I believe debug systems are usually overlooked, and yet they&#8217;re one of the most important systems in terms of productivity the second there&#8217;s any sorts of problems.\u00a0 And there will be problems!<br \/>\nNotice here that this requirement may sort of conflict with req #4.\u00a0 If there&#8217;s no debug messages compiled in, there&#8217;s no point in creating some of these extra exotic views.<br \/>\nNow with all that said, this should probably be added in as a requirement since it will affect the way things are designed, but I think this is a little overkill since right now I only need the console output.\u00a0 I just want to keep this in mind though so I can add it in the future.<\/p>\n<p><strong>3. test output<\/strong><br \/>\nThe logger would also work well for printing out test results.\u00a0 And given the proper formatting and tags, the test output could be written to an xml file in a way that allows for a viewer later on to give a tree view of test results. You can then open and close tests and see more information about them, or whether they passed on a high level.<\/p>\n<p>&nbsp;<\/p>\n<p>What else would you like to see in a debug logger?<\/p>\n","protected":false},"excerpt":{"rendered":"<p>Well I&#8217;ve finally gotten some time to get back into a bit of programming.\u00a0 I&#8217;ve been beating myself up cause I just haven&#8217;t had time with school, but now I&#8217;ve got a little bit of downtime so I plan on taking advantage of it. Sadly, it had been so long since I had looked at [&hellip;]<\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[1],"tags":[],"class_list":["post-39","post","type-post","status-publish","format-standard","hentry","category-uncategorized"],"_links":{"self":[{"href":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/wp-json\/wp\/v2\/posts\/39","targetHints":{"allow":["GET"]}}],"collection":[{"href":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/wp-json\/wp\/v2\/comments?post=39"}],"version-history":[{"count":5,"href":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/wp-json\/wp\/v2\/posts\/39\/revisions"}],"predecessor-version":[{"id":43,"href":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/wp-json\/wp\/v2\/posts\/39\/revisions\/43"}],"wp:attachment":[{"href":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/wp-json\/wp\/v2\/media?parent=39"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/wp-json\/wp\/v2\/categories?post=39"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/GetOffMyLawnEntertainment.com\/blog\/wp-json\/wp\/v2\/tags?post=39"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}