More Bums on Seats

Actuance’s collaboration on Help Training Courses gets a mention in the ‘If we can you can’ newsletter this month. You can read the full article here… ‘Shildon-based entrepreneurs put bums on seats’.

A simple servlet filter for Java performance logging

There are plenty of fancy tools for performance testing Java web applications but in addition to thorough load and volume testing before an application goes live, sometimes it’s useful just to leave simple perfomance monitoring running full time in a production environment. Monitoring the time the server takes to execute requests on your site can help you spot trends that let you anticipate and deal with problems caused by load, volume, unanticipated usage patterns or simply a database in need of some tuning. A proactive approach to performance tuning can bring big wins in customer satisfaction too, allowing you to pre-empt and avoid issues and keep your site running smoothly for your users.

Fortunately Java Enterprise Edition provides an easy mechanism for intercepting every request on the way in and out of the application in the form of a Servlet filter and it’s really simple to use that to create a performance logger. The basic concept here is to capture the time as a request enters an application, then again as it leaves and log the difference between the two. We can do this in the servlet filter’s doFilter method as follows. I’m using a log4j logger to handle the output but obviously any other logging mechanism would work just as well if you prefer something else:

    long startTime;
    long endTime;
    String path = ((HttpServletRequest) request).getServletPath();

    startTime = System.currentTimeMillis();
    chain.doFilter(request, response);
    endTime = System.currentTimeMillis();

    //Log the servlet path and time taken
    perfLogger.info(path + "," + (endTime - startTime) );

To finish off the code, I’ve added a couple of configuration options for more flexibility. For starters, I prefer to have a little more control over which URLs get logged than the standard servlet url-pattern mechanism allows. For instance, I may want to only log requests containing the word ’search’ anywhere in the path. The standard servlet url-pattern mechanism doesn’t allow this so I’ve added a parameter ‘url-filter’ to allow full regular expression matching. A second parameter ‘log-category’ sets the log4j logging category to use. Wrapping this into a full example servlet filter we get:

package com.actuanceconsulting.perflog;

import java.io.IOException;

import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;

import org.apache.log4j.Logger;

/**
 * A simple filter to log the time taken to execute a request. Logging is carried
 * out via log4j to give the flexibility to add other data (such as current time)
 * and format the log as required.
 * */

 /*
 * Copyright John Patrick, Actuance Consulting Limited 2010
 * http://www.actuanceconsulting.com
 *
 * This program is free software: you can redistribute it and/or modify
 * it under the terms of the GNU General Public License as published by
 * the Free Software Foundation, either version 3 of the License, or
 * (at your option) any later version.
 *
 * This program is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 * GNU General Public License for more details.
 *
 * For a copy of the GNU General Public License, see <http://www.gnu.org/licenses/>.
 */
public class PerformanceLogFilter implements Filter {

 /**
 * An optional regular expression to use as a filter for the servlet patch.
 * Gives more flexibility than the standard servlet url-filter.
 * All requests are logged if not specified.
 * */
 private static final String URL_FILTER_PARAM = "url-filter";

 /**
 * An optional log4j category to use. The fully qualified class name
 * of the filter will be used if not specified.
 */
 private static final String LOG_CATEGORY_PARAM = "log-category"; 

 private Logger perfLogger;
 private String urlFilter;

 public void init(FilterConfig config) throws ServletException {
    String logCategory = config.getInitParameter(LOG_CATEGORY_PARAM);
    if (logCategory == null) {
       this.getClass().getName();
    }
    perfLogger = Logger.getLogger(logCategory);
    urlFilter = config.getInitParameter(URL_FILTER_PARAM);
 }

 public void doFilter(ServletRequest request, ServletResponse response,
 FilterChain chain) throws IOException, ServletException {

    long startTime;
    long endTime;
    String path = ((HttpServletRequest) request).getServletPath();

    if (urlFilter == null || path.matches(urlFilter)) {
       startTime = System.currentTimeMillis();
       chain.doFilter(request, response);
       endTime = System.currentTimeMillis();

       //Log the servlet path and time taken
       perfLogger.info(path + "," + (endTime - startTime) );
    }
    else {
       chain.doFilter(request, response);            
    }
 }

 public void destroy() {
    //Nothing to see here        
 }

}

To get the filter to run, we need to configure it in the web.xml file as follows:

<filter>
  <filter-name>performance</filter-name>
  <filter-class>com.actuanceconsulting.perflog.PerformanceLogFilter</filter-class>
  <init-param>
    <param-name>url-filter</param-name>
    <param-value>.*search.*</param-value>
  </init-param>
  <init-param>
    <param-name>log-category</param-name>
    <param-value>perflog</param-value>
  </init-param>
</filter>
<filter-mapping>
  <filter-name>performance</filter-name>
  <url-pattern>/*</url-pattern>
</filter-mapping>

In this case I’ve set my regular expression for the ‘url-filter’ parameter to only match paths containing ’search’. For completeness, here’s the log4j config I used too…

<appender name="PerformanceFileAppender">
  <param name="Threshold" value="DEBUG"/>    
  <param name="File" value="../logs/performance.log"/>
  <param name="Append" value="true"/>
  <layout>
    <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss},%m%n"/>
  </layout>
</appender>

<category name="perflog">
  <priority value="INFO"/>        
  <appender-ref ref="PerformanceFileAppender"/>                
</category>

…and that produces output as shown below. The CSV format of this output allows for easy analysis of the results but obviously you can choose whatever format suits you best.

2010-06-19 11:26:20,/search,81
2010-06-19 11:26:25,/advanced-search-input,66
2010-06-19 11:26:30,/advanced-search,62
2010-06-19 11:26:39,/search,56
2010-06-19 11:26:43,/search,38
2010-06-19 11:26:43,/search,39

And that’s all there is to it. It’s a simple bit of code but it can really add value when run over a period of live operation. Being able to see historical performance and spot trends can be a powerful diagnostic tool.

Search that (nearly) passes the Turing test

After spending a fair bit of time over the past few months developing a search facility that was a bit more ‘human’ in its responses than a simple text-based search would be, I was interested to stumble on this discussion on Applying Turing’s Ideas to Search by John Ferrara. In my case, by working in just one niche  (training courses), the problem of creating more intelligent responses that the article discusses became more realistic. Even relatively simple implementations of some of the ideas gave some pretty powerful and less frustrating advantages from a usability perspective.

As a simple example, a search containing the word ‘free’ such as ‘free training’ clearly means to us humans that we want to see a price of zero, so matching ‘free climbing’ and ignoring £0 in the results clearly seems completely mental to the average user. The fix is pretty simple though. By enriching our search index with extra ‘implied’ data (like including the word ‘free’ when the price is zero) and choosing careful weightings for this data, the results quickly become far less ‘dumb’ and even at times appear surprisingly human. Obviously not always 100% perfect, but definitely better.

Automating our understanding of phrases (rather than simply isolated words) fascinates me too. I did a search today on a stock photo library for ‘Mac keyboard and mouse’. The intent of that search is clear enough to us humans but the starkly Turing-failing response was “By ‘Mac’ do you mean Apple Macintosh or Waterproof Clothing; By ‘keyboard’ do you mean computer input device, synthesizer or piano; By ‘mouse’ do you mean rodent or computer mouse?” Er, yes, I want a picture of a small rodent in a raincoat playing piano please.

That challenge for clarification is a reasonable enough question for a machine to ask but us humans know that when ‘keyboard and mouse’ are mentioned together in the same phrase, we’re pretty certain it doesn’t mean a piano-playing rodent. An what’s more, when keyboard and mouse are mentioned together with ‘Mac’, we know we’re not going to be wearing the mac.

What really fascinates me about all this isn’t really the deep, deep theory of it all (I’m a pragmatist at heart), but simply that a recognition and awareness of the weaknesses of ‘pure’ computer logic when we’re designing computer interfaces can quickly lead to huge steps forward in the usability of a system. By putting some thought into covering predictable and reasonable human expectations in a user interface, it’s relatively easy to avoid forcing your users to think like a computer, and even create a surprisingly positive experience.

From a personal perspective, what is often surprising when I start down this line of thinking, is that relatively little changes and increases in effort can bring big usability results. Even attempting (and inevitably failing) to make your user interface pass the Turing test still gives some real advantages to your users.

New Help Training Courses site goes live

For those of you following the progress of Help Training Courses, the web site went into public beta at www.helptrainingcourses.com earlier this week. The site started as a collaboration between Actuance and successful local training startup, Help First Aid Training back in November but quickly grew into a full new venture in it’s own right. It’s been a fun project to work on, with the main technical focus being a highly tailored search engine to pull the right results from the course listings and automation of travel industry style last minute discounts.

Our motto quickly became ‘more bums on seats’ and that’s exactly what the site aims to achieve, i.e. filling part-full courses and finding the training and deals that people actually want.

If you’re a training provider, please feel free to register and give us some early feedback.

Css rounded corners without images

I found a neat summary on Jon Raasch’s blog of a technique for producing rounded corners in IE using a behaviour htc file.

I’d previously been trying out this jquery corner plugin which works well enough but I think Jon’s suggestion is cleaner and allows Firefox, Chrome and Safari to achieve the effect completely natively with no javascript. Some care is needed with inline elements as Jon points out but other than that it’s a quick and effective solution that works well for me.

Browser javascript speed comparison – IE, Firefox, Chrome, Safari and Opera

I did some work recently on an interactive mapping interface which included optimising some processor-intensive Javascript for increased performance. Along the way I was surprised to learn just how different the Javascript performance was of various current-generation browsers. I was expecting some difference, and definitely expected older browsers to be slower but the speed difference of even modern Javascript engines was wildly different. As part of the work, the clients asked for recommendations on a fast browser so I decided to run some quick controlled tests to compare browser speed in this particular application. Here’s what I found…

Running the tests

To remove external influences such as network time from the tests, I ran everything locally and added some timing code around a particularly heavy bit of Javascript processing which wasn’t downloading data. The code was filtering and processing thousands of geographical points and adding them to an OpenLayers driven map, but the detail isn’t too important. The important point is that exactly the same code was run in each browser.

I used recent builds of the following browsers:

• Internet Explorer 8
• Firefox 3.6
• Chrome 4.1
• Safari 4.0
• Opera 10.5

Each browser was tested on the same machine under Windows XP 32 bit with a 2.4GHz dual core CPU and 4GB RAM (slightly less available due to the 32 bit limit). Minimal other processes were running and the CPU was near idle between tests. For each browser, an untimed run was carried out first to allow the browser a fair chance to cache static resources, then three timed runs were carried out, monitoring CPU to ensure it was ‘idle’ at no more than a few percent before and after each test and checking that memory didn’t max out (in reality there was at least 2GB of memory free during the tests).

Results

The raw timings in seconds were:

And showing that graphically in speed order from fastest to slowest…

Average timings for each browser in seconds (shortest bar is fastest)

While Javascript performance isn’t the only reason to choose a browser, it is an increasing factor when running modern interactive web applications and you can see that in my application at least, there’s a huge difference, with Internet Explorer being an order of magnitude behind the competition. Safari takes the performance lead in my case, followed closely by Google Chrome.

Every application’s different though so if you have any timings of your own that agree with or differ from these, please feel free to comment with your own results.