Java J2EE フィルタでWebアプリ・ページのロード時間を計測してみる

import java.io.IOException;
import java.text.DateFormat;
import java.text.SimpleDateFormat;
import java.util.Calendar;
import java.util.Date;

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.commons.logging.Log;
import org.apache.commons.logging.LogFactory;

/** Webページのロード時間計測・フィルタ **/
public class CalcPageLoadingTimeFilter implements Filter {
    /*
     * (non Javadoc)
     * 
     * @see javax.servlet.Filter#doFilter(javax.servlet.ServletRequest,
     *      javax.servlet.ServletResponse, javax.servlet.FilterChain)
     */
    public void doFilter(ServletRequest request, ServletResponse response,
            FilterChain chain) throws IOException, ServletException {
        Log log = LogFactory.getLog(CalcPageLoadingTimeFilter.class);

        Date startTime = Calendar.getInstance().getTime();
        long startTimeLong = Calendar.getInstance().getTimeInMillis();

        String uri = ((HttpServletRequest) request).getRequestURI();
        boolean logTime = false;
        if (uri.indexOf(".jsp") > 0) {  //Webページロード時間のログ出力条件
            logTime = true;
        }

        if (logTime) {
            log.info("[TIME-CALC]URI:" + uri);
            String formatedTime = formatDate(startTime,
                    "yy.MM.dd HH:mm:ss");
            log.info("[TIME-CALC]Start:" + formatedTime);
        }

        try {
            chain.doFilter(request, response);
        } finally {
            Date endTime = Calendar.getInstance().getTime();
            long endTimeLong = Calendar.getInstance().getTimeInMillis();

            if (logTime) {
                String formatedTime = formatDate(endTime,
                        "yy.MM.dd HH:mm:ss");
                log.info("[TIME-CALC]End:" + formatedTime);
                log.info("[TIME-CALC]Total:" + (endTimeLong - startTimeLong)
                        + "ms. " + (endTimeLong - startTimeLong) / 1000 + "s.");
            }
        }
    }

    private static final String formatDate(Date date, String pattern) {
        DateFormat df =
            new SimpleDateFormat(pattern);
        
        return df.format(date);
        
    }
    public void init(FilterConfig filterConfig) throws ServletException {

    }

    public void destroy() {

    }
}

<!-- 抜粋 -->
...
 <!-- Filter -->
 <filter>
  <filter-name>CalcPageLoadingTimeFilter</filter-name>
  <filter-class>CalcPageLoadingTimeFilter</filter-class>
 </filter>

 <!-- filter-mapping -->
 <filter-mapping>
  <filter-name>CalcPageLoadingTimeFilter</filter-name>
  <url-pattern>/*</url-pattern>
 </filter-mapping>
...

...
2009-07-29 17:16:22,565 INFO  [http-8080-Processor25] filter.CalcPageLoadingTimeFilter (CalcPageLoadingTimeFilter.java:44) - [TIME-CALC]URI:/some.jsp
2009-07-29 17:16:22,736 INFO  [http-8080-Processor25] filter.CalcPageLoadingTimeFilter (CalcPageLoadingTimeFilter.java:47) - [TIME-CALC]Start:08.02.29 17:16:22
...
...
2009-07-29 17:16:29,080 INFO  [http-8080-Processor25] filter.CalcPageLoadingTimeFilter (CalcPageLoadingTimeFilter.java:58) - [TIME-CALC]End:08.02.29 17:16:29
2009-07-29 17:16:29,080 INFO  [http-8080-Processor25] filter.CalcPageLoadingTimeFilter (CalcPageLoadingTimeFilter.java:61) - [TIME-CALC]Total:6515ms. 6s.
...