View Javadoc
1   /**
2    * Logback: the reliable, generic, fast and flexible logging framework.
3    * Copyright (C) 1999-2015, QOS.ch. All rights reserved.
4    *
5    * This program and the accompanying materials are dual-licensed under
6    * either the terms of the Eclipse Public License v1.0 as published by
7    * the Eclipse Foundation
8    *
9    *   or (per the licensee's choosing)
10   *
11   * under the terms of the GNU Lesser General Public License version 2.1
12   * as published by the Free Software Foundation.
13   */
14  package ch.qos.logback.classic.spi;
15  
16  import static org.junit.Assert.assertTrue;
17  import static org.junit.Assert.fail;
18  
19  import java.io.IOException;
20  import java.io.ObjectOutputStream;
21  
22  import ch.qos.logback.core.testUtil.EnvUtilForTests;
23  import org.junit.After;
24  import org.junit.Before;
25  import org.junit.Test;
26  import org.slf4j.MDC;
27  
28  import ch.qos.logback.classic.net.NOPOutputStream;
29  import ch.qos.logback.classic.net.testObjectBuilders.Builder;
30  import ch.qos.logback.classic.net.testObjectBuilders.LoggingEventWithParametersBuilder;
31  import ch.qos.logback.classic.net.testObjectBuilders.TrivialLoggingEventBuilder;
32  import ch.qos.logback.core.CoreConstants;
33  
34  // As of logback 0.9.15, 
35  //   average time  per logging event: 3979 nanoseconds
36  //   size 545'648 bytes
37  // 
38  // Using LoggingEventDO
39  // 
40  //   average time  per logging event: 4052 nanoseconds
41  //   average size=45,  with params, average size=136
42  //
43  // Using LoggerEventVO, with loggerName, and loggerContextRemoteView
44  //   average time per logging event: 4034
45  //   average size 57, with params, average size=148
46  
47  public class LoggingEventSerializationPerfTest {
48  
49      static int LOOP_LEN = 10 * 1000;
50  
51      NOPOutputStream noos = new NOPOutputStream();
52      ObjectOutputStream oos;
53  
54      @Before
55      public void setUp() throws Exception {
56          MDC.clear();
57          oos = new ObjectOutputStream(noos);
58      }
59  
60      @After
61      public void tearDown() throws Exception {
62      }
63  
64      double doLoop(Builder<LoggingEvent> builder, int loopLen) {
65          long start = System.nanoTime();
66          int resetCounter = 0;
67          for (int i = 0; i < loopLen; i++) {
68              try {
69                  ILoggingEvent le = builder.build(i);
70                  oos.writeObject(LoggingEventVO.build(le));
71  
72                  oos.flush();
73                  if (++resetCounter >= CoreConstants.OOS_RESET_FREQUENCY) {
74                      oos.reset();
75                      resetCounter = 0;
76                  }
77  
78              } catch (IOException ex) {
79                  fail(ex.getMessage());
80              }
81          }
82          long end = System.nanoTime();
83          return (end - start) / (1.0d * loopLen);
84      }
85  
86      @Test
87      public void testPerformance() {
88          if (EnvUtilForTests.isLinux()) {
89              return;
90          }
91          TrivialLoggingEventBuilder builder = new TrivialLoggingEventBuilder();
92  
93          for (int i = 0; i < 3; i++) {
94              doLoop(builder, LOOP_LEN);
95              noos.reset();
96          }
97          double rt = doLoop(builder, LOOP_LEN);
98          System.out.println("average time per logging event " + rt + " nanoseconds");
99  
100         long averageSize = (long) (noos.size() / (LOOP_LEN));
101         System.out.println("noos size " + noos.size() + " average size=" + averageSize);
102         double averageSizeLimit = 62.1;
103 
104         assertTrue("average size " + averageSize + " should be less than " + averageSizeLimit, averageSizeLimit > averageSize);
105 
106         // the reference was computed on Orion (Ceki's computer)
107         @SuppressWarnings("unused")
108         long referencePerf = 5000;
109         //BogoPerf.assertDuration(rt, referencePerf, CoreConstants.REFERENCE_BIPS);
110     }
111 
112     @Test
113     public void testPerformanceWithParameters() {
114         if (EnvUtilForTests.isLinux()) {
115             return;
116         }
117         LoggingEventWithParametersBuilder builder = new LoggingEventWithParametersBuilder();
118 
119         // warm up
120         for (int i = 0; i < 3; i++) {
121             doLoop(builder, LOOP_LEN);
122             noos.reset();
123         }
124         @SuppressWarnings("unused")
125         double rt = doLoop(builder, LOOP_LEN);
126         long averageSize = (long) (noos.size() / (LOOP_LEN));
127 
128         System.out.println("noos size " + noos.size() + " average size=" + averageSize);
129 
130         double averageSizeLimit = 160;
131         assertTrue("averageSize " + averageSize + " should be less than " + averageSizeLimit, averageSizeLimit > averageSize);
132 
133         // the reference was computed on Orion (Ceki's computer)
134         @SuppressWarnings("unused")
135         long referencePerf = 7000;
136         //BogoPerf.assertDuration(rt, referencePerf, CoreConstants.REFERENCE_BIPS);
137     }
138 }