[aspectj-users] Log tuning example submission

[Ken Horn <ken.horn@xxxxxxxxxxx>]

Attached are two files that implement a simple tuning aspect -- 
identifying redundant logging statements. I thought I'd submit them as 
an example to the list (perhaps to make it on to the contributions web 
site).

The background to this example, is that I had a medium size app that 
was running slowly, and I guessed that excessive logging could be the 
cause (there were thousands of inner loops in wacky sequences, hence 
extensive tracing was present). On running the original version of this 
on the problem project, I found over 1 million log.debug(..) calls that 
were typically switched off. In fact, wrapping half a dozen locations 
with isDebugEnabled() checks reduced this number to a few hundred.. 
performance got a big kick (probably due to the string creation as part 
of the call rather than the redundant call itself).

The code is a little rough but illustrates the technique, and is 
hopefully easy enough to follow. The frequency of reporting is adjusted 
via HiddenLogReporter.displayInterval

Comments / fixes welcome...

Regards,

Ken.

PS I/you can change copyright etc to Eclipse / CPL if needed.

Attachment: HiddenLogAspect.aj
Description: Binary data

/*
 * Created on Jun 2, 2004 (c) DarkSide Consulting Ltd 2004
 */
package dsc.ajdebug;

import java.util.ArrayList;
import java.util.Collections;
import java.util.HashMap;
import java.util.Iterator;
import java.util.List;
import java.util.Map;

import org.apache.log4j.Logger;
import org.aspectj.lang.JoinPoint;

/**
 * @author kenhorn
 */
public class HiddenLogReporter {

    private Map counts = new HashMap();

    private int total;

    private int displayInterval = 10;

    public void redundantFound(Logger log, JoinPoint.StaticPart jpsp) {
        incCounter(log, jpsp);

        total++;

        if (total % displayInterval == 0) {
            displayCounts();
        }

    }

    private void incCounter(Logger log, JoinPoint.StaticPart jpsp) {
        CallInstance ci = (CallInstance) counts.get(jpsp.getSourceLocation());
        if (ci == null) {
            ci = new CallInstance(jpsp, log);
            counts.put(jpsp.getSourceLocation(), ci);
        }
        ci.inc();
    }

    public void displayCounts() {
        List all = new ArrayList();
        all.addAll(counts.values());
        Collections.sort(all);
        Iterator it = all.iterator();

        System.out.println();
        System.out.println("-Redundant log statements summary--------------------");
        while (it.hasNext()) {
            System.out.println(it.next());
        }
        System.out.println("-----------------------------------------------------");
    }

    private class CallInstance implements Comparable {

        private JoinPoint.StaticPart jpsp;

        private Logger log;

        private int count;

        public int compareTo(Object o) {
            CallInstance ci = (CallInstance) o;
            return count - ci.count;
        }

        public CallInstance(JoinPoint.StaticPart jpsp, Logger log) {
            this.jpsp = jpsp;
            this.log = log;
        }

        public void inc() {
            count++;
        }

        public String toString() {
            return jpsp.getSourceLocation() + "\t" + log.getEffectiveLevel() + "\t" + count;
        }
    }
}