Wednesday, March 31, 2010

A middle-class man's conditional logging configuration

In an earlier post I described how one adapt a single configuration file for use in development as well as production environments. At those prehistoric times, that is January 2010, logback did not support conditional (if-then-else) configuration statements. So we made use of a default substitution value to do the the trick.

However, as of version 0.9.20 (to be released early April), logback supports conditional configuration statements. Thus, we can write:
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<if condition='!isNull("catalina.home")'>
<then>
<File>${catalina.home}/logs/myApp.log</File>
</then>
<else>
<File>./logs/myApp.log</File>
</else>
</if>
...
</appender>
Thus, if the "catalina.home" system property is defined (non null), then the log file will be written to ${catalina.home}/logs/myApp.log, otherwise, we are in the development environment and the logs should be written to ./logs/myApp.log.

In this particular case, the if-then-else approach is more verbose than default variable substitution, i.e. simply writing ${catalina.home:-.}. However, it goes without saying that conditional configuration brings much needed flexibility to the table. Keep in mind that given the verbosity of XML, one could gradually end up with a configuration file containing many logical branches rendering the file ungrokable. In case you ask, nested if-then-else statements are supported. So please use conditionals with moderation so that complexity does not creep into your configuration files.

Sunday, March 28, 2010

Dealing with ignorable errors

In real-world applications assembled out of heterogeneous parts or interacting with systems beyond your control, error conditions are bound to occur. Often times, some of these errors can be safely ignored. For example, the qos.ch e-commerce site is crawled by googlebot which for some unknown reason insists on visiting invalid URLs about 30-50 times a day. These invalid requests cause the wicket server to throw exceptions of type WicketRuntimeException.

Given that Wicket relies on SLF4J for logging, the WicketRuntimeException is logged as an error. To keep abreast of errors in our e-commerce applications, we use SMTPAppender in our logging configuration. Thus, every event logged as an error triggers an email to our site's administrator. As you can imagine, receiving over 30 emails per day as a result of erroneous Googlebot submissions defeats the purpose of these log report sent by email. (After the 100th bogus email, the admin stops caring.)

Below is a configuration file which instructs SMTPAppedner to ignore errors generated by Googlebot.
<configuration scan="true">
  <statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener" />
  <appender name="EMAIL" class="ch.qos.logback.classic.net.SMTPAppender">
    <layout class="ch.qos.logback.classic.html.HTMLLayout">
      <pattern>
        %date%-5level%thread%X{req.remoteHost}%logger%msg
      </pattern>
    </layout>
    <From>...</From>
    <SMTPHost>...</SMTPHost>
    <Subject>[${HOSTNAME}] %msg</Subject>
    <To>...</To>
    <evaluator class="ch.qos.logback.classic.boolex.JaninoEventEvaluator">
      <expression>
      level>=WARN
        &amp;&amp;
      !( mdc.get("req.userAgent") != null &amp;&amp; ((String) mdc.get("req.userAgent")).contains("Googlebot"))
      </expression>
    </evaluator>
  </appender>

  <root level="INFO">
    <appender-ref ref="EMAIL" />
  </root>
</configuration>

It relies heavily on JaninoEventEvaluator and requires the installation of MDCInsertingServletFilter.

You could also throw in markers into the mix as described in a previous post. It should be noted that the googlebot problem should be addressed by setting an internal error page but that's a different story.