From 23cfd671bd93d3a4e107eaea1951a67e9556cb32 Mon Sep 17 00:00:00 2001 From: Sander de Groot Date: Sat, 2 Jul 2016 13:02:05 +0200 Subject: [PATCH] Added simple "performance-test" which allows you to compare performance between difference modes a bit. --- pom.xml | 7 ++ ...eredContextualAppenderPerformanceTest.java | 89 +++++++++++++++++++ 2 files changed, 96 insertions(+) create mode 100644 src/test/java/com/github/sdegroot/logback/logbuffer/BufferedContextualAppenderPerformanceTest.java diff --git a/pom.xml b/pom.xml index 97c2018..2e2ef61 100644 --- a/pom.xml +++ b/pom.xml @@ -104,6 +104,13 @@ 2.0.0.0 test + + + org.apache.commons + commons-lang3 + 3.4 + test + diff --git a/src/test/java/com/github/sdegroot/logback/logbuffer/BufferedContextualAppenderPerformanceTest.java b/src/test/java/com/github/sdegroot/logback/logbuffer/BufferedContextualAppenderPerformanceTest.java new file mode 100644 index 0000000..ef38ec1 --- /dev/null +++ b/src/test/java/com/github/sdegroot/logback/logbuffer/BufferedContextualAppenderPerformanceTest.java @@ -0,0 +1,89 @@ +package com.github.sdegroot.logback.logbuffer; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.classic.spi.LoggingEvent; +import org.apache.commons.lang3.time.StopWatch; +import org.junit.Before; +import org.junit.Test; + +import static org.mockito.Mockito.mock; + +/** + * This is a "performance test" that doesn't assert anything. It just shows the differences a bit. + */ +public class BufferedContextualAppenderPerformanceTest { + + private BufferedContextualAppender bufferedContextualAppender; + private BufferedAppenderWrapper stubAppender; + + @Before + public void setUp() { + stubAppender = mock(BufferedAppenderWrapper.class); + bufferedContextualAppender = new BufferedContextualAppender(stubAppender, 50); + bufferedContextualAppender.setBufferFrom(Level.DEBUG); + bufferedContextualAppender.setBufferUntil(Level.INFO); + bufferedContextualAppender.setFlushBufferFrom(Level.WARN); + bufferedContextualAppender.setLogMessagesAfterFlush(true); + bufferedContextualAppender.setDropBelowBufferFrom(true); + } + + @Test + public void Calls1000WithoutBufferFlush() { + final StopWatch stopWatch = new StopWatch(); + stopWatch.start(); + + for (int i = 0; i < 1000; i++) { + bufferedContextualAppender.doAppend(createLoggingEvent(Level.DEBUG)); + } + + stopWatch.stop(); + ; + printStats(stopWatch, "1000 without buffer flush"); + } + + @Test + public void DirectCalls1000WithoutBuffer() { + final StopWatch stopWatch = new StopWatch(); + stopWatch.start(); + + for (int i = 0; i < 1000; i++) { + stubAppender.appendDirectly(createLoggingEvent(Level.DEBUG)); + } + + stopWatch.stop(); + ; + printStats(stopWatch, "1000 without buffer"); + } + + @Test + public void Calls1000WithBufferFlushEvery50() { + final StopWatch stopWatch = new StopWatch(); + stopWatch.start(); + + for (int i = 0; i < 1000; i++) { + Level level = Level.DEBUG; + if (i % 50 == 0) { + level = Level.WARN; // trigger buffer flush + } + bufferedContextualAppender.doAppend(createLoggingEvent(level)); + + } + + stopWatch.stop(); + printStats(stopWatch, "1000 with buffer flush"); + } + + private void printStats(StopWatch stopWatch, String stat) { + final long msTime = stopWatch.getTime(); + final long nsTime = stopWatch.getNanoTime(); + System.out.println(stat + " took " + nsTime + "ns (" + msTime + "ms)"); + } + + private static ILoggingEvent createLoggingEvent(Level level) { + final LoggingEvent loggingEvent = new LoggingEvent(); + loggingEvent.setLevel(level); + return loggingEvent; + } + +}