Skip navigation
2005

Dimitris Andreadis's Blog

April 2005 Previous month Next month
dimitris

Text Rulez!

Posted by dimitris Apr 24, 2005

 

Writing GUIs was never my forte and AFAIR the only "graphical" thing I've ever made (that I was actually proud of) was the user interface for a "pronounceable password generator". That was back in the college (1992?) where the assignment had been to create a password management system that would reduce the probability of having the users picking up bad password. Most students formed teams and build complex systems with Windows GUIs and dictionaries and rules to check password strength, and databases to record the passwords in use, so that you wouldn't choose it twice and stuff like that.

 

Being lazy to write any sort of persistence logic or complex GUI, I followed a different path. I worked on a algorithm that would produce completely random 10 characters words that would be nevertheless pronounceable (in English), so that you could actually memorize them. That resulted in about a dozen billion combinations of letters which was quite ok, but the fun stuff was that the system didn't have to keep any record at all about your choice (that would make the whole system less secure anyway) and the GUI collapsed to a single page with a text window in the middle. By pressing <space> the password generator was activated and passwords started rolling in that window at high speed (like symbols would roll in a slot machine). Pressing <space> a second time would stop that and the last ten password would show on the screen. You would start the engine again, until you had found a password that made your fancy. <esc> stopped the program and cleared the screen :)

 

That was coded in C, with the only non-standard C library call the gotoxy(int x, int y) from the Borland library. My solution to the problem was stupid enough to have a good chance of being useful and I got the 2nd best grade with a fraction of the code the other teams wrote. Most importantly I completely avoided having to learn Windows GUI programming :)

 

Now why I'm saying all this? While looking into making available through the jmx-console the memory pool information provided by the MemoryPoolMXBeans introduced in JDK5, I came across this text diagram that explains what the various memory pool metrics mean, in particular init, used, committed and max. The simple text diagram was so much nicer than the text explanation that I thought I should give it a try; for old time's sake :)

 

You can see the result here.

 

Text Rulez! :)

 

dimitris@jboss

 

To begin with, I'm a big fun of logging. In fact, I rarely use a debugger and only as a last resort. I've always believed that code is best debugged in your "head", as long as you know what you are doing. (It could be also that I'm just a louzy IDE user :)

 

For a long time, I admired the JBoss org.jboss.logging.Logger "wrapper" for a couple of reasons: the API is small, simple, and it only includes 5 + 1 levels of logging: ERROR, WARN, INFO, DEBUG & TRACE. (there is the FATAL level, but I doubt if it is ever used, it should be removed, really.)

 

Whenever you want to log something, it is almost a no-brainer to pick up the right logging level:

  • ERROR - A definite problem
  • WARN - Likely a problem, but can live with it
  • INFO - Common notifications, lifecycle stuff
  • DEBUG - Low volume debug
  • TRACE - High volume debug
(Compare this to java.util.logging.Logger ALL, CONFIG, FINE, FINER, FINEST, INFO, OFF, SEVER, WARNING, levels, or the entering() exiting() methods. It's almost hilarious!)

 

Then, there were those isInfoEnabled(), isDebugEnabled(), isTraceEnabled() performance enhancers that you could call in order to avoid preparing expensive logging output, that is never used. And as a sensible developer, I'd always use isDebugEnabled() whenever I would log.debug(..) any non-trivial stuff.

 

And all was well, until Adrian deprecated isDebugEnabled() (and isInfoEnabled()), and suddently the build bursted with ugly warnings, and eclipse started showing up those tiny yellow signs next to the slide bar. The code was not clean anymore...

 

Well, I could understand deprecating isInfoEnabled() (which is almost *always* enabled), but why isDebugEnabled()? Why now? Why me? That was cruel; we grew up with this method, we couldn't possibly live without it :)

 

Then as I started correcting warnings as I would come across them, by either removing the isDebugEnabled() statement all together, for logging messages that seemed of low-volume and of interest to the user, or turning this to a isTraceEnabled()/log.trace() combo for very detailed developer or high traffic logging messages, it all became clear: isLogDebug() was really not needed!

 

That was quite a revelation which brought to my mind pictures of Adrian with a "helo" hovering over his head (I've seen Richard Stallman doing this stunt wearing an "ancient" 1-foot hard disk as a helo, preaching his is Saint Ignucious, or something). Yes, Adrian, was telling the truth, and noboby listened (except Scott, of course :)

 

So now I'm a believer, too, and on top of that, I came to realise (or acknowledge?) that there is an ever better way to think about the log levels: INFO goes *always* to the console, DEBUG *always* to server.log, and TRACE *conditionally* to server.log. (ERROR and WARN are obvious.)

 

The usage of isDebugEnabled() gave the wrong impression that those debug messages may not be logged, which is rarely true. server.log is a tool primarily for the *users* of the server, to be able to troubleshoot problems and ask for help using informative log traces, from the forums (or the jboss support team of course :). In this regard, it is important that we don't log.debug() excessive information that is of no interest to the user; In other word, server.log size should always be kept relatively small or under control.

 

Another factor that isDebugEnabled() has been abused is due to the fact that in many cases we (developers) have used DEBUG for high traffic logging, that should really be TRACE. The reason being, we (developers) are usually lazy to enable the TRACE level in log4j.xml while developing, and we prefer to just use debug() instead, that we know it will work by default!

 

"If the user doesn't like this, she can turn if off", while the idea should really be, "I need to enable TRACE while I do development, and save server.log from being filled up with garbage, and the user from getting lost inside my verbose traces".

 

Happy Logging :)

 

dimitris@jboss

Filter Blog

By date: