1 /*
2 * Copyright (c) 2011, 2014, Oracle and/or its affiliates. All rights reserved.
3 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
4 *
5 * This code is free software; you can redistribute it and/or modify it
6 * under the terms of the GNU General Public License version 2 only, as
7 * published by the Free Software Foundation. Oracle designates this
8 * particular file as subject to the "Classpath" exception as provided
9 * by Oracle in the LICENSE file that accompanied this code.
10 *
11 * This code is distributed in the hope that it will be useful, but WITHOUT
12 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
13 * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
14 * version 2 for more details (a copy is included in the LICENSE file that
15 * accompanied this code).
16 *
17 * You should have received a copy of the GNU General Public License version
18 * 2 along with this work; if not, write to the Free Software Foundation,
19 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
20 *
21 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
22 * or visit www.oracle.com if you need additional information or have any
23 * questions.
24 */
25
26 package com.sun.webkit.perf;
27
28 import com.sun.javafx.logging.PlatformLogger;
29 import com.sun.javafx.logging.PlatformLogger.Level;
30 import java.util.ArrayList;
31 import java.util.Collections;
32 import java.util.Comparator;
33 import java.util.HashMap;
34 import java.util.Map;
35
36 public final class PerfLogger {
37 private static Thread shutdownHook;
38 private static Map<PlatformLogger, PerfLogger> loggers;
39
40 private final HashMap<String, ProbeStat> probes =
41 new HashMap<String, ProbeStat>();
42 private final PlatformLogger log;
43 private final boolean isEnabled; // needed at shutdown time
44
45 /**
46 * Finds or creates a logger with the given {@code log}.
47 * In order the logger be enabled the {@code log} should be loggable.
48 *
49 * @param log associated {@code Logger}
50 */
51 public synchronized static PerfLogger getLogger(PlatformLogger log) {
52 if (loggers == null) {
53 loggers = new HashMap<PlatformLogger, PerfLogger>();
54 }
55 PerfLogger l = loggers.get(log);
56 if (l == null) {
57 l = new PerfLogger(log);
58 loggers.put(log, l);
59 }
60 // Add the hook if at least one logger is enabled.
61 if (l.isEnabled() && shutdownHook == null) {
62 shutdownHook = new Thread() {
63 @Override
64 public void run() {
65 for (PerfLogger l: loggers.values()) {
66 if (!l.isEnabled()) continue;
67 // Using stdout as logging might be off at shutdown time.
68 l.log(false);
69 }
70 }
71 };
72 Runtime.getRuntime().addShutdownHook(shutdownHook);
73 }
74 return l;
75 }
76
77 /**
78 * Finds or creates a logger with {@code Logger} named
79 * com.sun.webkit.perf.{@code name}.
80 *
81 * @param name the {@code PerfLogger} short name
82 */
83 public synchronized static PerfLogger getLogger(String name) {
84 return getLogger(PlatformLogger.getLogger("com.sun.webkit.perf." + name));
85 }
86
87 private PerfLogger(PlatformLogger log) {
88 this.log = log;
89 this.isEnabled = log.isLoggable(Level.FINE);
90 startCount("TOTALTIME");
91 }
92
93 /**
94 * The class contains perf statistics for a registered probe.
95 */
96 public static final class ProbeStat {
97 private final String probe;
98 private int count;
99 private long totalTime;
100 private long startTime;
101 private boolean isRunning = false;
102
103 private ProbeStat(String probe) {
104 this.probe = probe;
105 }
106
107 public String getProbe() {
108 return probe;
109 }
110
111 public int getCount() {
112 return count;
113 }
114
115 public long getTotalTime() {
116 return totalTime;
117 }
118
119 private void reset() {
120 count = 0;
121 totalTime = startTime = 0;
122 }
123
124 private void suspend() {
125 if (isRunning) {
126 totalTime += System.currentTimeMillis() - startTime;
127 isRunning = false;
128 }
129 }
130
131 private void resume() {
132 isRunning = true;
133 count++;
134 startTime = System.currentTimeMillis();
135 }
136
137 private void snapshot() {
138 if (isRunning) {
139 totalTime += System.currentTimeMillis() - startTime;
140 startTime = System.currentTimeMillis();
141 }
142 }
143
144 @Override
145 public String toString() {
146 return super.toString() + "[count=" + count + ", time=" + totalTime + "]";
147 }
148 }
149
150 public boolean isEnabled() {
151 return isEnabled;
152 }
153
154 private synchronized String fullName(String probe) {
155 return log.getName() + "." + probe;
156 }
157
158 private final Comparator timeComparator = (arg0, arg1) -> {
159 long t0 = probes.get((String)arg0).totalTime;
160 long t1 = probes.get((String)arg1).totalTime;
161 if (t0 > t1) {
162 return 1;
163 } else if (t0 < t1) {
164 return -1;
165 }
166 return 0;
167 };
168
169 private final Comparator countComparator = (arg0, arg1) -> {
170 long c0 = probes.get((String)arg0).count;
171 long c1 = probes.get((String)arg1).count;
172 if (c0 > c1) {
173 return 1;
174 } else if (c0 < c1) {
175 return -1;
176 }
177 return 0;
178 };
179
180 /**
181 * Resets perf statistics.
182 */
183 public synchronized void reset() {
184 for (Map.Entry<String, ProbeStat> entry: probes.entrySet()) {
185 entry.getValue().reset();
186 }
187 startCount("TOTALTIME");
188 }
189
190 public synchronized static void resetAll() {
191 for (PerfLogger l: loggers.values()) {
192 l.reset();
193 }
194 }
195
196 private synchronized ProbeStat registerProbe(String probe) {
197 String p = probe.intern();
198 if (probes.containsKey(p)) {
199 log.fine("Warning: \"" + fullName(p) + "\" probe already exists");
200 } else {
201 log.fine("Registering \"" + fullName(p) + "\" probe");
202 }
203 ProbeStat stat = new ProbeStat(p);
204 probes.put(p, stat);
205 return stat;
206 }
207
208 public synchronized ProbeStat getProbeStat(String probe) {
209 String p = probe.intern();
210 ProbeStat s = probes.get(p);
211 if (s != null) {
212 s.snapshot();
213 }
214 return s;
215 }
216
217 /**
218 * Starts count statistics for the probe with zero initial data.
219 */
220 public synchronized void startCount(String probe) {
221 if (!isEnabled()) {
222 return;
223 }
224 String p = probe.intern();
225 ProbeStat stat = probes.get(p);
226 if (stat == null) {
227 stat = registerProbe(p);
228 }
229 stat.reset();
230 stat.resume();
231 }
232
233 /**
234 * Suspends count statistics for the probe.
235 */
236 public synchronized void suspendCount(String probe) {
237 if (!isEnabled()) {
238 return;
239 }
240 String p = probe.intern();
241 ProbeStat stat = probes.get(p);
242 if (stat != null) {
243 stat.suspend();
244 } else {
245 log.fine("Warning: \"" + fullName(p) + "\" probe is not registered");
246 }
247 }
248
249 /**
250 * Resumes count statistics for the probe, or starts if it's not yet started.
251 */
252 public synchronized void resumeCount(String probe) {
253 if (!isEnabled()) {
254 return;
255 }
256 String p = probe.intern();
257 ProbeStat stat = probes.get(p);
258 if (stat == null) {
259 stat = registerProbe(p);
260 }
261 stat.resume();
262 }
263
264 /**
265 * Prints perf statistics to the buffer.
266 */
267 public synchronized void log(StringBuffer buf) {
268 if (!isEnabled()) {
269 return;
270 }
271 buf.append("=========== Performance Statistics =============\n");
272
273 ProbeStat total = getProbeStat("TOTALTIME");
274
275 ArrayList<String> list = new ArrayList<String>();
276 list.addAll(probes.keySet());
277
278 buf.append("\nTime:\n");
279 Collections.sort(list, timeComparator);
280 for (String p: list) {
281 ProbeStat s = getProbeStat(p);
282 buf.append(String.format("%s: %dms", fullName(p), s.totalTime));
283 if (total.totalTime > 0){
284 buf.append(String.format(", %.2f%%%n", (float)100*s.totalTime/total.totalTime));
285 } else {
286 buf.append("\n");
287 }
288 }
289
290 buf.append("\nInvocations count:\n");
291 Collections.sort(list, countComparator);
292 for (String p: list) {
293 buf.append(String.format("%s: %d%n", fullName(p), getProbeStat(p).count));
294 }
295 buf.append("================================================\n");
296 }
297
298 /**
299 * Logs perf statistics.
300 */
301 public synchronized void log() {
302 log(true);
303 }
304
305 private synchronized void log(boolean useLogger) {
306 StringBuffer buf = new StringBuffer();
307 log(buf);
308 if (useLogger) {
309 log.fine(buf.toString());
310 } else {
311 System.out.println(buf.toString());
312 System.out.flush();
313 }
314 }
315
316 /**
317 * Logs perf statistics of all loggers.
318 */
319 public synchronized static void logAll() {
320 for (PerfLogger l: loggers.values()) {
321 l.log();
322 }
323 }
324 }