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 java.io.FileWriter;
017import java.io.IOException;
018
019import org.slf4j.Logger;
020
021import ch.qos.logback.classic.LoggerContext;
022import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
023import ch.qos.logback.classic.spi.ILoggingEvent;
024import ch.qos.logback.core.FileAppender;
025import ch.qos.logback.core.util.StatusPrinter;
026
027public class IOPerformance extends Thread {
028    static String MSG = "ABCDEGHIJKLMNOPQRSTUVWXYZabcdeghijklmnopqrstuvwxyz1234567890";
029    static String LOG_FILE;
030    public static String PARALLEL_FILE;
031
032    static int NUM_THREADS = 1;
033    static long l;
034    long len;
035    boolean immediateFlush;
036    Logger logger;
037    LoggerContext context;
038    double throughput;
039
040    public IOPerformance(boolean _immediateFlush, long _len) {
041        this.len = _len;
042        this.immediateFlush = _immediateFlush;
043        context = new LoggerContext();
044        logger = context.getLogger("logger-" + getName());
045
046        // A FileAppender is created according to the buffering and
047        // immediate flush setting of this IO instance.
048        FileAppender<ILoggingEvent> fa = new FileAppender<ILoggingEvent>();
049        fa.setName("FILE");
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
056        fa.setFile(LOG_FILE);
057        fa.setAppend(true);
058        fa.setContext(context);
059        fa.start();
060
061        ((ch.qos.logback.classic.Logger) logger).addAppender(fa);
062
063        StatusPrinter.print(context);
064    }
065
066    public static void main(String[] argv) throws Exception {
067        if (argv.length != 3) {
068            usage("Wrong number of arguments.");
069        }
070
071        l = Integer.parseInt(argv[0]);
072        LOG_FILE = argv[1];
073        PARALLEL_FILE = argv[2];
074
075        // ----------------------------------------------------
076        // first test with immediate flushing
077        perfCase(true, l);
078
079        // ----------------------------------------------------
080        // Second test with no immediate flushing
081        perfCase(false, l);
082
083        // There is no fourth test as buffered IO and immediate flushing
084        // do not make sense.
085    }
086
087    static void usage(String msg) {
088        System.err.println(msg);
089        System.err.println("Usage: java " + IOPerformance.class.getName() + " runLength logFile otherFile\n"
090                        + "   runLength (integer) the number of logs to generate perthread\n" + "   logFile path to a logFile\n"
091                        + "   otherFile path to a second file\n");
092        System.exit(1);
093    }
094
095    static void perfCase(boolean immediateFlush, long len) throws Exception {
096        IOPerformance[] threads = new IOPerformance[NUM_THREADS];
097        OtherIO otherIOThread = new OtherIO();
098        otherIOThread.start();
099
100        // First create the threads
101        for (int i = 0; i < NUM_THREADS; i++) {
102            threads[i] = new IOPerformance(immediateFlush, len);
103        }
104
105        // then start them
106        for (int i = 0; i < NUM_THREADS; i++) {
107            threads[i].start();
108        }
109
110        // wait for them to processPriorToRemoval, compute the average throughput
111        double sum = 0;
112
113        for (int i = 0; i < NUM_THREADS; i++) {
114            threads[i].join();
115            sum += threads[i].throughput;
116        }
117
118        // setting the interrupted field will cause counterThread to processPriorToRemoval
119        otherIOThread.interrupted = true;
120        otherIOThread.join();
121
122        System.out.println("On total throughput of " + (sum) + " logs per microsecond.");
123        System.out.println("------------------------------------------------");
124    }
125
126    public void run() {
127
128        long before = System.nanoTime();
129
130        for (int i = 0; i < len; i++) {
131            logger.debug(MSG);
132        }
133
134        throughput = (len * 1.0) / ((System.nanoTime() - before) / 1000);
135        System.out.println(getName() + ", immediateFlush: " + immediateFlush + ", throughput: " + throughput + " logs per microsecond.");
136    }
137}
138
139class OtherIO extends Thread {
140    public boolean interrupted = false;
141    public int counter = 0;
142
143    public void run() {
144        long before = System.nanoTime();
145        try {
146            FileWriter fw = new FileWriter(IOPerformance.PARALLEL_FILE, true);
147
148            while (!interrupted) {
149                counter++;
150                fw.write("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx");
151                fw.flush();
152            }
153        } catch (IOException e) {
154            e.printStackTrace();
155        }
156
157        double tput = (counter * 1.0) / (System.nanoTime() - before);
158        System.out.println("Counter thread " + getName() + " incremented counter by " + tput + " per nanosecond.");
159    }
160}