001/** 002 * Logback: the reliable, generic, fast and flexible logging framework. 003 * Copyright (C) 1999-2015, QOS.ch. All rights reserved. 004 * 005 * This program and the accompanying materials are dual-licensed under 006 * either the terms of the Eclipse Public License v1.0 as published by 007 * the Eclipse Foundation 008 * 009 * or (per the licensee's choosing) 010 * 011 * under the terms of the GNU Lesser General Public License version 2.1 012 * as published by the Free Software Foundation. 013 */ 014package chapters.appenders; 015 016import org.slf4j.Logger; 017 018import ch.qos.logback.classic.LoggerContext; 019import ch.qos.logback.classic.encoder.PatternLayoutEncoder; 020import ch.qos.logback.classic.spi.ILoggingEvent; 021import ch.qos.logback.core.FileAppender; 022import ch.qos.logback.core.encoder.EchoEncoder; 023 024public class IO extends Thread { 025 static String msgLong = "ABCDEGHIJKLMNOPQRSTUVWXYZabcdeghijklmnopqrstuvwxyz1234567890"; 026 static String msgShort = "Hello"; 027 static boolean scarceCPU; 028 static int numThreads; 029 static long l; 030 static boolean longMessage; 031 long len; 032 boolean buffered; 033 boolean immediateFlush; 034 Logger logger; 035 LoggerContext context; 036 double throughput; 037 038 public IO(boolean _buffered, boolean _immediateFlush, long _len) { 039 this.len = _len; 040 this.buffered = _buffered; 041 this.immediateFlush = _immediateFlush; 042 context = new LoggerContext(); 043 logger = context.getLogger("logger-" + getName()); 044 045 // A FileAppender is created according to the buffering and 046 // immediate flush setting of this IO instance. 047 FileAppender<ILoggingEvent> fa = new FileAppender<ILoggingEvent>(); 048 049 if (longMessage) { 050 PatternLayoutEncoder pa = new PatternLayoutEncoder(); 051 pa.setPattern("%r %5p %c [%t] - %m%n"); 052 pa.setContext(context); 053 pa.start(); 054 fa.setEncoder(pa); 055 } else { 056 fa.setEncoder(new EchoEncoder<ILoggingEvent>()); 057 } 058 059 fa.setFile(getName() + ".log"); 060 fa.setAppend(false); 061 fa.setContext(context); 062 fa.start(); 063 064 } 065 066 public static void main(String[] argv) throws Exception { 067 if (argv.length != 4) { 068 usage("Wrong number of arguments."); 069 } 070 071 l = Integer.parseInt(argv[0]); 072 numThreads = Integer.parseInt(argv[1]); 073 scarceCPU = "true".equalsIgnoreCase(argv[2]); 074 longMessage = "long".equalsIgnoreCase(argv[3]); 075 076 // ---------------------------------------------------- 077 // first test with unbuffered IO and immediate flushing 078 perfCase(false, true, l); 079 080 // ---------------------------------------------------- 081 // Second test with unbuffered IO and no immediate flushing 082 perfCase(false, false, l); 083 084 // ---------------------------------------------------- 085 // Third test with buffered IO and no immediate flushing 086 perfCase(true, false, l); 087 088 // There is no fourth test as buffered IO and immediate flushing 089 // do not make sense. 090 } 091 092 static void usage(String msg) { 093 System.err.println(msg); 094 System.err.println("Usage: java " + IO.class.getName() + " runLength numThreads scarceCPU (short|long)\n" 095 + " runLength (integer) the number of logs to generate perthread\n" + " numThreads (integer) the number of threads.\n" 096 + " scarceCPU (boolean) if true an additional CPU intensive thread is created\n" + " (short|long) length of log messages."); 097 System.exit(1); 098 } 099 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 156class 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}