1 package org.djutils.profile;
2
3 import java.util.Collections;
4 import java.util.LinkedHashMap;
5 import java.util.Map;
6 import java.util.Map.Entry;
7 import java.util.TreeMap;
8
9 import org.djutils.exceptions.Throw;
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27 public final class Profile
28 {
29
30
31 private static final Map<String, ProfileInfo> INFOS = new LinkedHashMap<>();
32
33
34 private static final Map<String, String> LINES = new LinkedHashMap<>();
35
36
37 private static long printInterval = 1000;
38
39
40 private static long lastPrint = 0;
41
42
43 private Profile()
44 {
45
46 }
47
48
49
50
51 public static void start()
52 {
53 start0(null, System.nanoTime());
54 }
55
56
57
58
59
60 public static void start(final String name)
61 {
62 start0(name, System.nanoTime());
63 }
64
65
66
67
68
69
70 private static void start0(final String name, final Long nanoTime)
71 {
72 getProfileInfo(name, true).start(nanoTime);
73 }
74
75
76
77
78 public static void end()
79 {
80 end0(null, System.nanoTime());
81 }
82
83
84
85
86
87 public static void end(final String name)
88 {
89 end0(name, System.nanoTime());
90 }
91
92
93
94
95
96
97 private static void end0(final String name, final Long nanoTime)
98 {
99 getProfileInfo(name, false).end(nanoTime);
100 }
101
102
103
104
105
106
107
108 private static ProfileInfo getProfileInfo(final String name, final boolean start)
109 {
110 StackTraceElement element = Thread.currentThread().getStackTrace()[4];
111 String classMethodId = element.getClassName() + ":" + element.getMethodName();
112 String partId;
113 if (name == null)
114 {
115 if (start)
116 {
117 partId = ":" + String.valueOf(element.getLineNumber());
118 LINES.put(classMethodId, partId);
119 }
120 else
121 {
122 partId = LINES.get(classMethodId);
123 }
124 }
125 else
126 {
127 partId = ":" + name;
128 }
129 classMethodId += partId;
130
131 ProfileInfo info = INFOS.get(classMethodId);
132 if (info == null)
133 {
134 info = new ProfileInfo(name);
135 INFOS.put(classMethodId, info);
136 }
137 return info;
138 }
139
140
141
142
143
144 public static String statistics()
145 {
146
147 double sum = 0;
148 int maxInvocations = 0;
149 int maxNameLength = 4;
150 Map<Double, Entry<String, ProfileInfo>> sorted = new TreeMap<>(Collections.reverseOrder());
151 for (Entry<String, ProfileInfo> entry : INFOS.entrySet())
152 {
153 String id = entry.getKey();
154 ProfileInfo info = INFOS.get(id);
155 sorted.put(info.getTotal(), entry);
156 sum += info.getTotal();
157 maxInvocations = maxInvocations > info.getInvocations() ? maxInvocations : info.getInvocations();
158 int nameLength = (info.getName() == null ? id : info.getName()).length();
159 maxNameLength = maxNameLength > nameLength ? maxNameLength : nameLength;
160 }
161 int lengthInvoke = String.valueOf(maxInvocations).length();
162 lengthInvoke = lengthInvoke > 6 ? lengthInvoke : 6;
163 String invokeHeaderFormat = String.format("%%%d.%ds", lengthInvoke, lengthInvoke);
164 String invokeLineFormat = String.format("%%%ds", lengthInvoke);
165 String nameHeaderFormat = String.format("%%%d.%ds", maxNameLength, maxNameLength);
166 String nameLineFormat = String.format("%%%ds", maxNameLength);
167 String line = new String(new char[80 + lengthInvoke + maxNameLength]).replace("\0", "-");
168
169
170 StringBuilder builder = new StringBuilder();
171 builder.append("-").append(line).append("-\n");
172 builder.append(String.format("| %7.7s | ", "Perc."));
173 builder.append(String.format(invokeHeaderFormat, "#Calls"));
174 builder.append(String.format(" | %10.10s | %10.10s | %10.10s | %10.10s | %10.10s | ", "TotTime", "MinTime", "MaxTime",
175 "AvgTime", "StdTime"));
176 builder.append(String.format(nameHeaderFormat, "Name")).append(" |\n");
177 builder.append("|").append(line).append("|\n");
178
179
180 for (Entry<String, ProfileInfo> entry : sorted.values())
181 {
182 String id = entry.getKey();
183 ProfileInfo info = entry.getValue();
184 if (info.getInvocations() > 0)
185 {
186 double perc = 100.0 * info.getTotal() / sum;
187 builder.append(String.format("| %6.2f%% | ", perc));
188 builder.append(String.format(invokeLineFormat, info.getInvocations()));
189 builder.append(String.format(" | %9.4fs | %9.6fs | %9.6fs | %9.6fs | ", info.getTotal(), info.getMin(),
190 info.getMax(), info.getMean()));
191
192 if (info.getInvocations() > 1)
193 {
194 builder.append(String.format("%9.6fs", info.getStandardDeviation()));
195 }
196 else
197 {
198 builder.append(" ");
199 }
200
201 builder.append(" | ").append(String.format(nameLineFormat, info.getName() == null ? id : info.getName()))
202 .append(" |\n");
203 }
204 }
205 return builder.append("-").append(line).append("-\n").toString();
206 }
207
208
209
210
211
212
213 public static String statistics(final String name)
214 {
215 Throw.whenNull(name, "name may not be null");
216 for (ProfileInfo result : INFOS.values())
217 {
218 if (null == result)
219 {
220 return null;
221 }
222 if (name.equals(result.getName()))
223 {
224 return result.toString();
225 }
226 }
227 return null;
228 }
229
230
231
232
233
234
235
236 public static void print()
237 {
238 long t = System.currentTimeMillis();
239 if (t - lastPrint > printInterval)
240 {
241 lastPrint = t;
242 System.out.print(statistics());
243 }
244 }
245
246
247
248
249
250 public static void setPrintInterval(final long printInterval)
251 {
252 Profile.printInterval = printInterval;
253 }
254
255
256
257
258 public static void clear()
259 {
260 INFOS.clear();
261 LINES.clear();
262 }
263
264
265
266
267 public static void reset()
268 {
269 for (ProfileInfo pi : INFOS.values())
270 {
271 pi.reset();
272 }
273 }
274
275
276
277
278
279
280
281
282
283
284
285
286 private static class ProfileInfo
287 {
288
289 private static final double NANOSECONDSPERSECOND = 1000000000.0;
290
291
292 private final String name;
293
294
295 private Long start = null;
296
297
298 private long total;
299
300
301 private long totalSquared;
302
303
304 private long minTime;
305
306
307 private long maxTime;
308
309
310 private int invocations;
311
312
313
314
315
316 ProfileInfo(final String name)
317 {
318 this.name = name;
319 }
320
321
322
323
324 public void reset()
325 {
326 this.start = null;
327 this.total = 0;
328 this.totalSquared = 0;
329 this.minTime = 0;
330 this.maxTime = 0;
331 this.invocations = 0;
332 }
333
334
335
336
337
338 public void start(final long startTime)
339 {
340 Throw.when(this.start != null, IllegalStateException.class,
341 "Can not start profiling because it is already running.");
342 this.start = startTime;
343 }
344
345
346
347
348
349 public void end(final long endTime)
350 {
351 Throw.when(this.start == null, IllegalStateException.class, "Can not end profiling because it is not running.");
352 long duration = endTime - this.start;
353 this.total += duration;
354 this.totalSquared += duration * duration;
355 if (this.invocations == 0)
356 {
357 this.minTime = duration;
358 this.maxTime = duration;
359 }
360 else
361 {
362 this.minTime = this.minTime < duration ? this.minTime : duration;
363 this.maxTime = this.maxTime > duration ? this.maxTime : duration;
364 }
365 this.invocations++;
366 this.start = null;
367 }
368
369
370
371
372
373 public String getName()
374 {
375 return this.name;
376 }
377
378
379
380
381
382 public double getTotal()
383 {
384 return this.total / NANOSECONDSPERSECOND;
385 }
386
387
388
389
390
391 public double getStandardDeviation()
392 {
393 if (this.invocations < 2)
394 {
395 return Double.NaN;
396 }
397 double squared = this.totalSquared - this.total * this.total / this.invocations;
398 return Math.sqrt(squared / (this.invocations - 1)) / NANOSECONDSPERSECOND;
399 }
400
401
402
403
404
405 public int getInvocations()
406 {
407 return this.invocations;
408 }
409
410
411
412
413
414 public double getMean()
415 {
416 return getTotal() / getInvocations();
417 }
418
419
420
421
422
423 public double getMin()
424 {
425 return this.minTime / NANOSECONDSPERSECOND;
426 }
427
428
429
430
431
432 public double getMax()
433 {
434 return this.maxTime / NANOSECONDSPERSECOND;
435 }
436
437 @Override
438 public String toString()
439 {
440 return "ProfileInfo [name=" + this.name + ", start=" + this.start + ", total=" + this.total + ", totalSquared="
441 + this.totalSquared + ", minTime=" + this.minTime + ", maxTime=" + this.maxTime + ", invocations="
442 + this.invocations + "]";
443 }
444
445 }
446
447 }