StopwatchOverheadPerformanceTest by Erik van Oosten

This code accompanies the article Evaluating Simon.

Quick download link:
StopwatchOverheadPerformanceTest.java

/*
 * Copyright (c) 2008 Erik van Oosten.
 *
 * MIT license.
 *
 */
package nl.grons.javasimon;

import org.testng.annotations.Test;

import java.util.concurrent.*;
import java.util.List;
import java.util.ArrayList;

import org.javasimon.*;

//import com.jamonapi.Monitor;
//import com.jamonapi.MonitorFactory;

/**
 * Measures overhead of typical webapp /monitor usages in a higly threaded environment
 * for either Simon or Jamon.
 *
 * @author Erik van Oosten
 * @see http://day-to-day-stuff.blogspot.com/2008/12/evaluating-simon.html
 */
public class StopwatchOverheadPerformanceTest {

    private static enum Jiggle {
        NOOP {
            public void jiggle() throws Exception {
            }},
        YIELD {
            public void jiggle() throws Exception {
                Thread.yield();
            }},
        SLEEP {
            public void jiggle() throws Exception {
                Thread.sleep(0L);
            }},
        WAIT {
            public void jiggle() throws Exception {
                Object o = new Object();
                synchronized (o) {
                    o.wait(0L, 1);
                }
            }};
        public abstract void jiggle() throws Exception;
    }

    private static final Jiggle[] JIGGLES = new Jiggle[] {
            Jiggle.YIELD, Jiggle.NOOP, Jiggle.SLEEP, Jiggle.NOOP, Jiggle.WAIT, Jiggle.NOOP,
            Jiggle.SLEEP, Jiggle.NOOP, Jiggle.WAIT, Jiggle.NOOP, Jiggle.YIELD, Jiggle.NOOP,
            Jiggle.WAIT, Jiggle.NOOP, Jiggle.YIELD, Jiggle.NOOP, Jiggle.SLEEP, Jiggle.NOOP
    };

    @Test
    public void testStopwatch() throws Exception {
        testStopwatch(  4, 10000); // warming up
        testStopwatch(  1, 10000);
        testStopwatch(  2, 10000);
        testStopwatch(  4, 10000);
        testStopwatch( 16, 10000);
        testStopwatch( 32, 500000 / 32);
        testStopwatch( 50, 500000 / 50);
        testStopwatch(100, 500000 / 100);
        testStopwatch(150, 500000 / 150);
        testStopwatch(200, 500000 / 200);
    }

    private void testStopwatch(int threadCount, final int requestCount) throws Exception {
        // Testing Simon
        SimonManager.clear();
        // To fill up the data structures, create many stopwatches that we do not use
        for (int i = 0; i < 100; i++) {
            for (int j = 0; j < 100; j++) {
                SimonManager.getStopwatch("simon.test.i" + i + ".j" + j);
            }
        }
        // Pre-create the simons we will use
        SimonManager.getStopwatch("simon.test.all");
        for (int i = 0; i < 20; i++) {
            SimonManager.getStopwatch("simon.test.request" + i);
        }
        for (int i = 0; i < 100; i++) {
            SimonManager.getStopwatch("simon.test.service" + i);
        }
        for (int i = 0; i < 100; i++) {
            SimonManager.getStopwatch("simon.test.dao" + i);
        }

        // Testing Jamon
//        MonitorFactory.reset();
//        // To fill up the data structures, create many monitors that we do not use
//        for (int i = 0; i < 100; i++) {
//            for (int j = 0; j < 100; j++) {
//                MonitorFactory.getTimeMonitor("jamon.test.i" + i + ".j" + j);
//            }
//        }
//        // Pre-create the monitors we will use
//        MonitorFactory.getTimeMonitor("jamon.test.all");
//        for (int i = 0; i < 20; i++) {
//            MonitorFactory.getTimeMonitor("jamon.test.request" + i);
//        }
//        for (int i = 0; i < 100; i++) {
//            MonitorFactory.getTimeMonitor("jamon.test.service" + i);
//        }
//        for (int i = 0; i < 100; i++) {
//            MonitorFactory.getTimeMonitor("jamon.test.dao" + i);
//        }

        ExecutorService executor = Executors.newFixedThreadPool(threadCount);
        final CountDownLatch startLatch = new CountDownLatch(1);
        final CountDownLatch stopLatch = new CountDownLatch(threadCount);
        List<Future<Long>> testresults = new ArrayList<Future<Long>>(threadCount);
        for (int threadNumber = 0; threadNumber < threadCount; threadNumber++) {
            final int threadId = threadNumber;
            testresults.add(executor.submit(new Callable<Long>() {
                public Long call() throws Exception {
                    startLatch.await();

                    long simonTime = 0L;

                    try {
                        long start = System.nanoTime();
                        for (int request = 0; request < requestCount; request++) {
                            Stopwatch allSimon = SimonManager.getStopwatch("simon.test.all").start();
                            int simonOffset = request + threadId;
                            Stopwatch requestSimon = SimonManager.getStopwatch("simon.test.request" + (simonOffset % 20)).start();
                            Stopwatch serviceSimon = SimonManager.getStopwatch("simon.test.service" + (simonOffset % 100)).start();
                            int daoCount = request % 3;
                            for (int daoCall = 0; daoCall < daoCount; daoCall++) {
                                Stopwatch daoSimon = SimonManager.getStopwatch("simon.test.dao" + ((simonOffset + daoCall) % 100)).start();

                                simonTime += System.nanoTime() - start;
                                JIGGLES[request % JIGGLES.length].jiggle();
                                start = System.nanoTime();

                                daoSimon.stop();
                            }
                            serviceSimon.stop();
                            requestSimon.stop();
                            allSimon.stop();

//                            Monitor allJamon = MonitorFactory.getTimeMonitor("jamon.test.all").start();
//                            int simonOffset = request + threadId;
//                            Monitor requestJamon = MonitorFactory.getTimeMonitor("jamon.test.request" + (simonOffset % 20)).start();
//                            Monitor serviceJamon = MonitorFactory.getTimeMonitor("jamon.test.service" + (simonOffset % 100)).start();
//                            int daoCount = request % 3;
//                            for (int daoCall = 0; daoCall < daoCount; daoCall++) {
//                                Stopwatch daoJamon = SimonManager.getStopwatch("jamon.test.dao" + ((simonOffset + daoCall) % 100)).start();
//
//                                simonTime += System.nanoTime() - start;
//                                JIGGLES[request % JIGGLES.length].jiggle();
//                                start = System.nanoTime();
//
//                                daoJamon.stop();
//                            }
//                            serviceJamon.stop();
//                            requestJamon.stop();
//                            allJamon.stop();

                            simonTime += System.nanoTime() - start;
                            JIGGLES[request % JIGGLES.length].jiggle();
                            start = System.nanoTime();
                        }

                        simonTime += System.nanoTime() - start;
                        return simonTime;

                    } catch (Exception ex) {
                        ex.printStackTrace(System.err);
                        throw ex;
                    } finally {
                        stopLatch.countDown();
                    }
                }
            }));
        }

        startLatch.countDown();
        stopLatch.await();

        executor.shutdownNow();

        long threadTotalTimeMillis = 0L;
        for (Future<Long> testresult : testresults) {
            threadTotalTimeMillis += testresult.get();
        }

        // per request:
        // - all timer
        // - 1 request specific timer
        // - 1 service timer
        // - 1 on average; once every 3 requests there are 0, 1 and 2 dao timers
        long simonCount = threadCount * (4 * requestCount);

        System.out.printf(
                "Thread count: %3d  Avg simon time: %8d ns\n",
                threadCount,
                threadTotalTimeMillis / simonCount);
    }

}