1
2
3
4
5
6
7
8
9
10
11
12
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
46
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
78 perfCase(false, true, l);
79
80
81
82 perfCase(false, false, l);
83
84
85
86 perfCase(true, false, l);
87
88
89
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
110 for (int i = 0; i < numThreads; i++) {
111 threads[i] = new IO(buffered, immediateFlush, len);
112 }
113
114
115 for (int i = 0; i < numThreads; i++) {
116 threads[i].start();
117 }
118
119
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
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 }