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 chapters.appenders;
15  
16  import org.slf4j.Logger;
17  
18  import ch.qos.logback.classic.LoggerContext;
19  import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
20  import ch.qos.logback.classic.spi.ILoggingEvent;
21  import ch.qos.logback.core.FileAppender;
22  import ch.qos.logback.core.encoder.EchoEncoder;
23  
24  public class IO extends Thread {
25      static String msgLong = "ABCDEGHIJKLMNOPQRSTUVWXYZabcdeghijklmnopqrstuvwxyz1234567890";
26      static String msgShort = "Hello";
27      static boolean scarceCPU;
28      static int numThreads;
29      static long l;
30      static boolean longMessage;
31      long len;
32      boolean buffered;
33      boolean immediateFlush;
34      Logger logger;
35      LoggerContext context;
36      double throughput;
37  
38      public IO(boolean _buffered, boolean _immediateFlush, long _len) {
39          this.len = _len;
40          this.buffered = _buffered;
41          this.immediateFlush = _immediateFlush;
42          context = new LoggerContext();
43          logger = context.getLogger("logger-" + getName());
44  
45          // A FileAppender is created according to the buffering and
46          // immediate flush setting of this IO instance.
47          FileAppender<ILoggingEvent> fa = new FileAppender<ILoggingEvent>();
48  
49          if (longMessage) {
50              PatternLayoutEncoder pa = new PatternLayoutEncoder();
51              pa.setPattern("%r %5p %c [%t] - %m%n");
52              pa.setContext(context);
53              pa.start();
54              fa.setEncoder(pa);
55          } else {
56              fa.setEncoder(new EchoEncoder<ILoggingEvent>());
57          }
58  
59          fa.setFile(getName() + ".log");
60          fa.setAppend(false);
61          fa.setContext(context);
62          fa.start();
63  
64      }
65  
66      public static void main(String[] argv) throws Exception {
67          if (argv.length != 4) {
68              usage("Wrong number of arguments.");
69          }
70  
71          l = Integer.parseInt(argv[0]);
72          numThreads = Integer.parseInt(argv[1]);
73          scarceCPU = "true".equalsIgnoreCase(argv[2]);
74          longMessage = "long".equalsIgnoreCase(argv[3]);
75  
76          // ----------------------------------------------------
77          // first test with unbuffered IO and immediate flushing
78          perfCase(false, true, l);
79  
80          // ----------------------------------------------------
81          // Second test with unbuffered IO and no immediate flushing
82          perfCase(false, false, l);
83  
84          // ----------------------------------------------------
85          // Third test with buffered IO and no immediate flushing
86          perfCase(true, false, l);
87  
88          // There is no fourth test as buffered IO and immediate flushing
89          // do not make sense.
90      }
91  
92      static void usage(String msg) {
93          System.err.println(msg);
94          System.err.println("Usage: java " + IO.class.getName() + " runLength numThreads scarceCPU (short|long)\n"
95                          + "   runLength (integer) the number of logs to generate perthread\n" + "   numThreads (integer) the number of threads.\n"
96                          + "   scarceCPU (boolean) if true an additional CPU intensive thread is created\n" + "   (short|long) length of log messages.");
97          System.exit(1);
98      }
99  
100     static void perfCase(boolean buffered, boolean immediateFlush, long len) throws Exception {
101         IO[] threads = new IO[numThreads];
102         Counter counterThread = null;
103 
104         if (scarceCPU) {
105             counterThread = new Counter();
106             counterThread.start();
107         }
108 
109         // First create the threads
110         for (int i = 0; i < numThreads; i++) {
111             threads[i] = new IO(buffered, immediateFlush, len);
112         }
113 
114         // then start them
115         for (int i = 0; i < numThreads; i++) {
116             threads[i].start();
117         }
118 
119         // wait for them to processPriorToRemoval, compute the average throughput
120         double sum = 0;
121 
122         for (int i = 0; i < numThreads; i++) {
123             threads[i].join();
124             sum += threads[i].throughput;
125         }
126 
127         if (scarceCPU) {
128             // setting the interrupted field will cause counterThread to processPriorToRemoval
129             counterThread.interrupted = true;
130             counterThread.join();
131         }
132 
133         System.out.println("On average throughput of " + (sum / numThreads) * 1000 + " logs per microsecond.");
134         System.out.println("------------------------------------------------");
135     }
136 
137     public void run() {
138         String msg = msgShort;
139 
140         if (longMessage) {
141             msg = msgLong;
142         }
143 
144         long before = System.nanoTime();
145 
146         for (int i = 0; i < len; i++) {
147             logger.debug(msg);
148         }
149 
150         throughput = (len * 1.0) / (System.nanoTime() - before);
151         System.out.println(getName() + ", buffered: " + buffered + ", immediateFlush: " + immediateFlush + ", throughput: " + throughput
152                         + " logs per nanosecond.");
153     }
154 }
155 
156 class Counter extends Thread {
157     public boolean interrupted = false;
158     public double counter = 0;
159 
160     public void run() {
161         long before = System.nanoTime();
162 
163         while (!interrupted) {
164             if (counter % 1000 == 0) {
165                 Thread.yield();
166             }
167             counter += 1.0;
168         }
169 
170         double tput = (counter * 1.0) / (System.nanoTime() - before);
171         System.out.println("Counter thread " + getName() + " incremented counter by " + tput + " per nanosecond.");
172     }
173 }