View Javadoc

1   /**
2    * Logback: the reliable, generic, fast and flexible logging framework.
3    * Copyright (C) 1999-2011, 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() +
95        " runLength numThreads scarceCPU (short|long)\n" +
96        "   runLength (integer) the number of logs to generate perthread\n" +
97        "   numThreads (integer) the number of threads.\n" +
98        "   scarceCPU (boolean) if true an additional CPU intensive thread is created\n" +
99        "   (short|long) length of log messages.");
100     System.exit(1);
101   }
102 
103   static void perfCase(boolean buffered, boolean immediateFlush, long len)
104     throws Exception {
105     IO[] threads = new IO[numThreads];
106     Counter counterThread = null;
107 
108     if (scarceCPU) {
109       counterThread = new Counter();
110       counterThread.start();
111     }
112 
113     // First create the threads 
114     for (int i = 0; i < numThreads; i++) {
115       threads[i] = new IO(buffered, immediateFlush, len);
116     }
117 
118     // then start them
119     for (int i = 0; i < numThreads; i++) {
120       threads[i].start();
121     }
122 
123     // wait for them to stop, compute the average throughput
124     double sum = 0;
125 
126     for (int i = 0; i < numThreads; i++) {
127       threads[i].join();
128       sum += threads[i].throughput;
129     }
130 
131     if (scarceCPU) {
132       // setting the interrupted field will cause counterThread to stop
133       counterThread.interrupted = true;
134       counterThread.join();
135     }
136 
137     System.out.println("On average throughput of " + (sum / numThreads)*1000 +
138       " logs per microsecond.");
139     System.out.println("------------------------------------------------");
140   }
141 
142   public void run() {
143     String msg = msgShort;
144 
145     if (longMessage) {
146       msg = msgLong;
147     }
148 
149     long before = System.nanoTime();
150 
151     for (int i = 0; i < len; i++) {
152       logger.debug(msg);
153     }
154 
155     throughput = (len * 1.0) / (System.nanoTime() - before);
156     System.out.println(getName() + ", buffered: " + buffered +
157       ", immediateFlush: " + immediateFlush + ", throughput: " + throughput +
158       " logs per nanosecond.");
159   }
160 }
161 
162 
163 class Counter extends Thread {
164   public boolean interrupted = false;
165   public double counter = 0;
166 
167   public void run() {
168     long before = System.nanoTime();
169 
170     while (!interrupted) {
171       if(counter % 1000 == 0) {
172           Thread.yield();
173       }
174       counter += 1.0;
175     }
176 
177     double tput = (counter * 1.0) / (System.nanoTime() - before);
178     System.out.println("Counter thread " + getName() +
179       " incremented counter by " + tput + " per nanosecond.");
180   }
181 }