View Javadoc
1   /**
2    * Logback: the reliable, generic, fast and flexible logging framework.
3    * Copyright (C) 1999-2015, QOS.ch. All rights reserved.
4    * <p>
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    * <p>
9    * or (per the licensee's choosing)
10   * <p>
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 ch.qos.logback.classic.net.NOPOutputStream;
17  import ch.qos.logback.classic.net.testObjectBuilders.Builder;
18  import ch.qos.logback.classic.net.testObjectBuilders.LoggingEventWithParametersBuilder;
19  import ch.qos.logback.classic.net.testObjectBuilders.TrivialLoggingEventBuilder;
20  import ch.qos.logback.core.CoreConstants;
21  import ch.qos.logback.core.testUtil.EnvUtilForTests;
22  import org.junit.jupiter.api.AfterEach;
23  import org.junit.jupiter.api.BeforeEach;
24  import org.junit.jupiter.api.Disabled;
25  import org.junit.jupiter.api.Test;
26  import org.slf4j.MDC;
27  
28  import java.io.IOException;
29  import java.io.ObjectOutputStream;
30  
31  import static org.junit.jupiter.api.Assertions.assertTrue;
32  import static org.junit.jupiter.api.Assertions.fail;
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  @Disabled
48  public class LoggingEventSerializationPerfTest {
49  
50      static int LOOP_LEN = 10 * 1000;
51  
52      NOPOutputStream noos = new NOPOutputStream();
53      ObjectOutputStream oos;
54  
55      @BeforeEach
56      public void setUp() throws Exception {
57          MDC.clear();
58          oos = new ObjectOutputStream(noos);
59      }
60  
61      @AfterEach
62      public void tearDown() throws Exception {
63      }
64  
65      double doLoop(Builder<LoggingEvent> builder, int loopLen) {
66          long start = System.nanoTime();
67          int resetCounter = 0;
68          for (int i = 0; i < loopLen; i++) {
69              try {
70                  ILoggingEvent le = builder.build(i);
71                  oos.writeObject(LoggingEventVO.build(le));
72  
73                  oos.flush();
74                  if (++resetCounter >= CoreConstants.OOS_RESET_FREQUENCY) {
75                      oos.reset();
76                      resetCounter = 0;
77                  }
78  
79              } catch (IOException ex) {
80                  fail(ex.getMessage());
81              }
82          }
83          long end = System.nanoTime();
84          return (end - start) / (1.0d * loopLen);
85      }
86  
87      @Test
88      public void testPerformance() {
89          if (EnvUtilForTests.isLinux()) {
90              return;
91          }
92          TrivialLoggingEventBuilder builder = new TrivialLoggingEventBuilder();
93  
94          for (int i = 0; i < 3; i++) {
95              doLoop(builder, LOOP_LEN);
96              noos.reset();
97          }
98          double rt = doLoop(builder, LOOP_LEN);
99          System.out.println("average time per logging event " + rt + " nanoseconds");
100 
101         long averageSize = (long) (noos.size() / (LOOP_LEN));
102         System.out.println("noos size " + noos.size() + " average size=" + averageSize);
103         double averageSizeLimit = 62.1;
104 
105         assertTrue(averageSizeLimit > averageSize, "average size " + averageSize + " should be less than " + averageSizeLimit);
106 
107         // the reference was computed on Orion (Ceki's computer)
108         @SuppressWarnings("unused")
109         long referencePerf = 5000;
110         // BogoPerf.assertDuration(rt, referencePerf, CoreConstants.REFERENCE_BIPS);
111     }
112 
113     @Test
114     public void testPerformanceWithParameters() {
115         if (EnvUtilForTests.isLinux()) {
116             return;
117         }
118         LoggingEventWithParametersBuilder builder = new LoggingEventWithParametersBuilder();
119 
120         // warm up
121         for (int i = 0; i < 3; i++) {
122             doLoop(builder, LOOP_LEN);
123             noos.reset();
124         }
125         @SuppressWarnings("unused")
126         double rt = doLoop(builder, LOOP_LEN);
127         long averageSize = (long) (noos.size() / (LOOP_LEN));
128 
129         System.out.println("noos size " + noos.size() + " average size=" + averageSize);
130 
131         double averageSizeLimit = 160;
132         assertTrue(averageSizeLimit > averageSize,
133                 "averageSize " + averageSize + " should be less than " + averageSizeLimit);
134 
135         // the reference was computed on Orion (Ceki's computer)
136         @SuppressWarnings("unused")
137         long referencePerf = 7000;
138         // BogoPerf.assertDuration(rt, referencePerf, CoreConstants.REFERENCE_BIPS);
139     }
140 }