Additional Log4j v2 performance tests

RunChronicle.java

package org.apache.logging.log4j.core.async.perftest;

import java.io.File;

import com.higherfrequencytrading.chronicle.Excerpt;
import com.higherfrequencytrading.chronicle.impl.IndexedChronicle;
import com.lmax.disruptor.collections.Histogram;

public final class RunChronicle implements IPerfTestRunner {
	@Override
	public void runThroughputTest(int lines, Histogram histogram) {
		try {
			final String basePath = System.getProperty("java.io.tmpdir")
					+ File.separator + "test";
			final IndexedChronicle chronicle = new IndexedChronicle(basePath);
			chronicle.useUnsafe(true); // for benchmarks.
			final Excerpt excerpt = chronicle.createExcerpt();

			final long s1 = System.nanoTime();
			for (int j = 0; j < lines; j++) {
				excerpt.startExcerpt(2 + 2 * THROUGHPUT_MSG.length());
				excerpt.writeChars(THROUGHPUT_MSG);
				excerpt.finish();
			}

			final long s2 = System.nanoTime();
			final long opsPerSec = (1000L * 1000L * 1000L * lines) / (s2 - s1);
			histogram.addObservation(opsPerSec);

			chronicle.close();
			new File(basePath).delete();
		} catch (Exception ex) {
			throw new RuntimeException(ex);
		}
	}

	@Override
	public void runLatencyTest(int samples, Histogram histogram,
			long nanoTimeCost, int threadCount) {
		try {
			final String basePath = System.getProperty("java.io.tmpdir")
					+ File.separator + "test";
			final IndexedChronicle chronicle = new IndexedChronicle(basePath);
			chronicle.useUnsafe(true); // for benchmarks.
			final Excerpt excerpt = chronicle.createExcerpt();

			for (int i = 0; i < samples; i++) {
				final long s1 = System.nanoTime();

				excerpt.startExcerpt(2 + 2 * THROUGHPUT_MSG.length());
				excerpt.writeChars(THROUGHPUT_MSG);
				excerpt.finish();

				final long s2 = System.nanoTime();
				final long value = s2 - s1 - nanoTimeCost;
				if (value > 0) {
					histogram.addObservation(value);
				}
				// wait 1 microsec
				final long PAUSE_NANOS = 10000 * threadCount;
				final long pauseStart = System.nanoTime();
				while (PAUSE_NANOS > (System.nanoTime() - pauseStart)) {
					// busy spin
				}
			}

			chronicle.close();
			new File(basePath).delete();
		} catch (Exception ex) {
			throw new RuntimeException(ex);
		}
	}

	@Override
	public void shutdown() {
		// TODO Auto-generated method stub

	}

	@Override
	public void log(String finalMessage) {
		System.out.println("Final message: " + finalMessage);
	}
}

RunUnsafe.java

package org.apache.logging.log4j.core.async.perftest;

import java.lang.reflect.Field;

import sun.misc.Unsafe;

import com.lmax.disruptor.collections.Histogram;

@SuppressWarnings("all")
public final class RunUnsafe implements IPerfTestRunner {
	@Override
	public void runThroughputTest(int lines, Histogram histogram) {
		try {
			int size = 10485760;
			final long buffer = UNSAFE.allocateMemory(size);
			long offset = 0;

			final long s1 = System.nanoTime();
			for (int j = 0; j < lines; j++) {
				char[] chars = (char[]) stringValue.get(THROUGHPUT_MSG);
				long new_offset = offset + chars.length;
				if (new_offset >= size) {
					offset = 0;
					new_offset = chars.length;
				}
				for (char c : chars) {
					long address = buffer + offset++;
					UNSAFE.putByte(address, (byte) (c & 0xFF));
				}
			}

			final long s2 = System.nanoTime();
			final long opsPerSec = (1000L * 1000L * 1000L * lines) / (s2 - s1);
			histogram.addObservation(opsPerSec);

			UNSAFE.freeMemory(buffer);
		} catch (Exception ex) {
			throw new RuntimeException(ex);
		}
	}

	@Override
	public void runLatencyTest(int samples, Histogram histogram,
			long nanoTimeCost, int threadCount) {
		try {
			int size = 10485760;
			final long buffer = UNSAFE.allocateMemory(size);
			long offset = 0;

			for (int i = 0; i < samples; i++) {
				final long s1 = System.nanoTime();

				char[] chars = (char[]) stringValue.get(THROUGHPUT_MSG);
				long new_offset = offset + chars.length;
				if (new_offset >= size) {
					offset = 0;
					new_offset = chars.length;
				}
				for (char c : chars) {
					long address = buffer + offset++;
					UNSAFE.putByte(address, (byte) (c & 0xFF));
				}

				final long s2 = System.nanoTime();
				final long value = s2 - s1 - nanoTimeCost;
				if (value > 0) {
					histogram.addObservation(value);
				}
				// wait 1 microsec
				final long PAUSE_NANOS = 10000 * threadCount;
				final long pauseStart = System.nanoTime();
				while (PAUSE_NANOS > (System.nanoTime() - pauseStart)) {
					// busy spin
				}
			}

			UNSAFE.freeMemory(buffer);
		} catch (Exception ex) {
			throw new RuntimeException(ex);
		}
	}

	@Override
	public void shutdown() {
		// TODO Auto-generated method stub

	}

	@Override
	public void log(String finalMessage) {
		System.out.println("Final message: " + finalMessage);
	}

	private static final Unsafe UNSAFE;
	private static final Field stringValue;

	static {
		try {
			Field theUnsafe = Unsafe.class.getDeclaredField("theUnsafe");
			theUnsafe.setAccessible(true);
			UNSAFE = (Unsafe) theUnsafe.get(null);
			stringValue = String.class.getDeclaredField("value");
			stringValue.setAccessible(true);
		} catch (Exception e) {
			throw new AssertionError(e);
		}
	}
}