Wednesday, November 29, 2006

Needles, haystacks, and log4j

There was an interesting bug report that came in to the MIFOS mailing list recently.

Someone was posting that they couldn't start MIFOS (that's not the interesting part). The interesting part was: "then I am Getting so many errors, List of the Errors is as follows." and lots of log4j output (in fact, too much for the mailing list archive program to show it all, so you'll need to take my word for what was there).

Most of the log4j output which was INFO messages which meant nothing at all was wrong. The trouble started with a WARN which started "org.hibernate.cfg.SettingsFactory -
Could not obtain connection metadata"
and proceeded with a stacktrace. Then another 19 or so INFO messages (not related to the error, as far as I can tell). Then another WARN, this one even more cryptic than the last: "org.hibernate.util.JDBCExceptionReporter - SQL Error:
1045, SQLState: 28000". Then finally an ERROR which fairly directly said what was wrong: "org.hibernate.util.JDBCExceptionReporter - Access
denied for user 'root'@'localhost' (using password:
YES)".

In other words, this was a simple problem (the database user and password that had been supplied to MIFOS were not set up in MySQL) but the actual error message was buried in some 1500 lines of red herrings.

It's no wonder that software gets a reputation for being hard to install/configure/run, when tracking down the simple problems involves this level of looking for a needle in a haystack.

For MIFOS, the low-hanging fruit seems pretty clear: make sure the default log4j logging level is set to WARN (in fact, I would have changed this already, except I couldn't find where it is being set - which is another good log4j rant but one for another time). Then all those INFO messages wouldn't be there. Bonus points would be given for: (1) reporting the real error once instead of 3 times (probably best done within Hibernate), and (2) making it so that one can go to localhost:8080/mifos (that is, the URL which would have had the application, had it started) and see an error message (or at least a hint - like "application failed to start - see xxx for detail").

No comments: