author | herrick |
Fri, 12 Jun 2009 14:56:32 -0400 | |
changeset 3111 | fefdeafb7ab9 |
parent 715 | f16baef3a20e |
child 5506 | 202f599c92aa |
permissions | -rw-r--r-- |
2 | 1 |
/* |
715 | 2 |
* Copyright 2002-2008 Sun Microsystems, Inc. All Rights Reserved. |
2 | 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. Sun designates this |
|
8 |
* particular file as subject to the "Classpath" exception as provided |
|
9 |
* by Sun 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 Sun Microsystems, Inc., 4150 Network Circle, Santa Clara, |
|
22 |
* CA 95054 USA or visit www.sun.com if you need additional information or |
|
23 |
* have any questions. |
|
24 |
*/ |
|
25 |
||
26 |
||
27 |
||
28 |
package sun.misc; |
|
29 |
||
30 |
import java.util.Vector; |
|
31 |
import java.io.FileWriter; |
|
32 |
import java.io.File; |
|
33 |
import java.io.OutputStreamWriter; |
|
34 |
import java.io.Writer; |
|
35 |
||
36 |
/** |
|
37 |
* This class is intended to be a central place for the jdk to |
|
38 |
* log timing events of interest. There is pre-defined event |
|
39 |
* of startTime, as well as a general |
|
40 |
* mechanism of setting aribtrary times in an array. |
|
41 |
* All unreserved times in the array can be used by callers |
|
42 |
* in application-defined situations. The caller is responsible |
|
43 |
* for setting and getting all times and for doing whatever |
|
44 |
* analysis is interesting; this class is merely a central container |
|
45 |
* for those timing values. |
|
46 |
* Note that, due to the variables in this class being static, |
|
47 |
* use of particular time values by multiple applets will cause |
|
48 |
* confusing results. For example, if plugin runs two applets |
|
49 |
* simultaneously, the initTime for those applets will collide |
|
50 |
* and the results may be undefined. |
|
51 |
* <P> |
|
52 |
* To automatically track startup performance in an app or applet, |
|
53 |
* use the command-line parameter sun.perflog as follows:<BR> |
|
54 |
* -Dsun.perflog[=file:<filename>] |
|
55 |
* <BR> |
|
56 |
* where simply using the parameter with no value will enable output |
|
57 |
* to the console and a value of "file:<filename>" will cause |
|
58 |
* that given filename to be created and used for all output. |
|
59 |
* <P> |
|
60 |
* By default, times are measured using System.currentTimeMillis(). To use |
|
61 |
* System.nanoTime() instead, add the command-line parameter:<BR> |
|
62 |
-Dsun.perflog.nano=true |
|
63 |
* <BR> |
|
64 |
* <P> |
|
65 |
* <B>Warning: Use at your own risk!</B> |
|
66 |
* This class is intended for internal testing |
|
67 |
* purposes only and may be removed at any time. More |
|
68 |
* permanent monitoring and profiling APIs are expected to be |
|
69 |
* developed for future releases and this class will cease to |
|
70 |
* exist once those APIs are in place. |
|
71 |
* @author Chet Haase |
|
72 |
*/ |
|
73 |
public class PerformanceLogger { |
|
74 |
||
75 |
// Timing values of global interest |
|
76 |
private static final int START_INDEX = 0; // VM start |
|
77 |
private static final int LAST_RESERVED = START_INDEX; |
|
78 |
||
79 |
private static boolean perfLoggingOn = false; |
|
80 |
private static boolean useNanoTime = false; |
|
51 | 81 |
private static Vector<TimeData> times; |
2 | 82 |
private static String logFileName = null; |
83 |
private static Writer logWriter = null; |
|
3111
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
84 |
private static long baseTime; |
2 | 85 |
|
86 |
static { |
|
87 |
String perfLoggingProp = |
|
88 |
java.security.AccessController.doPrivileged( |
|
89 |
new sun.security.action.GetPropertyAction("sun.perflog")); |
|
90 |
if (perfLoggingProp != null) { |
|
91 |
perfLoggingOn = true; |
|
92 |
||
93 |
// Check if we should use nanoTime |
|
94 |
String perfNanoProp = |
|
95 |
java.security.AccessController.doPrivileged( |
|
96 |
new sun.security.action.GetPropertyAction("sun.perflog.nano")); |
|
97 |
if (perfNanoProp != null) { |
|
98 |
useNanoTime = true; |
|
99 |
} |
|
100 |
||
101 |
// Now, figure out what the user wants to do with the data |
|
102 |
if (perfLoggingProp.regionMatches(true, 0, "file:", 0, 5)) { |
|
103 |
logFileName = perfLoggingProp.substring(5); |
|
104 |
} |
|
105 |
if (logFileName != null) { |
|
106 |
if (logWriter == null) { |
|
107 |
java.security.AccessController.doPrivileged( |
|
51 | 108 |
new java.security.PrivilegedAction<Void>() { |
109 |
public Void run() { |
|
2 | 110 |
try { |
111 |
File logFile = new File(logFileName); |
|
112 |
logFile.createNewFile(); |
|
113 |
logWriter = new FileWriter(logFile); |
|
114 |
} catch (Exception e) { |
|
115 |
System.out.println(e + ": Creating logfile " + |
|
116 |
logFileName + |
|
117 |
". Log to console"); |
|
118 |
} |
|
119 |
return null; |
|
120 |
} |
|
121 |
}); |
|
122 |
} |
|
123 |
} |
|
124 |
if (logWriter == null) { |
|
125 |
logWriter = new OutputStreamWriter(System.out); |
|
126 |
} |
|
127 |
} |
|
51 | 128 |
times = new Vector<TimeData>(10); |
2 | 129 |
// Reserve predefined slots |
130 |
for (int i = 0; i <= LAST_RESERVED; ++i) { |
|
131 |
times.add(new TimeData("Time " + i + " not set", 0)); |
|
132 |
} |
|
133 |
} |
|
134 |
||
135 |
/** |
|
136 |
* Returns status of whether logging is enabled or not. This is |
|
137 |
* provided as a convenience method so that users do not have to |
|
138 |
* perform the same GetPropertyAction check as above to determine whether |
|
139 |
* to enable performance logging. |
|
140 |
*/ |
|
141 |
public static boolean loggingEnabled() { |
|
142 |
return perfLoggingOn; |
|
143 |
} |
|
144 |
||
145 |
||
146 |
/** |
|
147 |
* Internal class used to store time/message data together. |
|
148 |
*/ |
|
149 |
static class TimeData { |
|
150 |
String message; |
|
151 |
long time; |
|
152 |
||
153 |
TimeData(String message, long time) { |
|
154 |
this.message = message; |
|
155 |
this.time = time; |
|
156 |
} |
|
157 |
||
158 |
String getMessage() { |
|
159 |
return message; |
|
160 |
} |
|
161 |
||
162 |
long getTime() { |
|
163 |
return time; |
|
164 |
} |
|
165 |
} |
|
166 |
||
167 |
/** |
|
168 |
* Return the current time, in millis or nanos as appropriate |
|
169 |
*/ |
|
170 |
private static long getCurrentTime() { |
|
171 |
if (useNanoTime) { |
|
172 |
return System.nanoTime(); |
|
173 |
} else { |
|
174 |
return System.currentTimeMillis(); |
|
175 |
} |
|
176 |
} |
|
177 |
||
178 |
/** |
|
179 |
* Sets the start time. Ideally, this is the earliest time available |
|
180 |
* during the startup of a Java applet or application. This time is |
|
181 |
* later used to analyze the difference between the initial startup |
|
182 |
* time and other events in the system (such as an applet's init time). |
|
183 |
*/ |
|
184 |
public static void setStartTime(String message) { |
|
185 |
if (loggingEnabled()) { |
|
186 |
long nowTime = getCurrentTime(); |
|
187 |
setStartTime(message, nowTime); |
|
188 |
} |
|
189 |
} |
|
190 |
||
191 |
/** |
|
3111
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
192 |
* Sets the base time, output can then |
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
193 |
* be displayed as offsets from the base time;. |
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
194 |
*/ |
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
195 |
public static void setBaseTime(long time) { |
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
196 |
if (loggingEnabled()) { |
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
197 |
baseTime = time; |
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
198 |
} |
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
199 |
} |
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
200 |
|
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
201 |
/** |
2 | 202 |
* Sets the start time. |
203 |
* This version of the method is |
|
204 |
* given the time to log, instead of expecting this method to |
|
205 |
* get the time itself. This is done in case the time was |
|
206 |
* recorded much earlier than this method was called. |
|
207 |
*/ |
|
208 |
public static void setStartTime(String message, long time) { |
|
209 |
if (loggingEnabled()) { |
|
210 |
times.set(START_INDEX, new TimeData(message, time)); |
|
211 |
} |
|
212 |
} |
|
213 |
||
214 |
/** |
|
215 |
* Gets the start time, which should be the time when |
|
216 |
* the java process started, prior to the VM actually being |
|
217 |
* loaded. |
|
218 |
*/ |
|
219 |
public static long getStartTime() { |
|
220 |
if (loggingEnabled()) { |
|
51 | 221 |
return times.get(START_INDEX).getTime(); |
2 | 222 |
} else { |
223 |
return 0; |
|
224 |
} |
|
225 |
} |
|
226 |
||
227 |
/** |
|
228 |
* Sets the value of a given time and returns the index of the |
|
229 |
* slot that that time was stored in. |
|
230 |
*/ |
|
231 |
public static int setTime(String message) { |
|
232 |
if (loggingEnabled()) { |
|
233 |
long nowTime = getCurrentTime(); |
|
234 |
return setTime(message, nowTime); |
|
235 |
} else { |
|
236 |
return 0; |
|
237 |
} |
|
238 |
} |
|
239 |
||
240 |
/** |
|
241 |
* Sets the value of a given time and returns the index of the |
|
242 |
* slot that that time was stored in. |
|
243 |
* This version of the method is |
|
244 |
* given the time to log, instead of expecting this method to |
|
245 |
* get the time itself. This is done in case the time was |
|
246 |
* recorded much earlier than this method was called. |
|
247 |
*/ |
|
248 |
public static int setTime(String message, long time) { |
|
249 |
if (loggingEnabled()) { |
|
250 |
// times is already synchronized, but we need to ensure that |
|
251 |
// the size used in times.set() is the same used when returning |
|
252 |
// the index of that operation. |
|
253 |
synchronized (times) { |
|
254 |
times.add(new TimeData(message, time)); |
|
255 |
return (times.size() - 1); |
|
256 |
} |
|
257 |
} else { |
|
258 |
return 0; |
|
259 |
} |
|
260 |
} |
|
261 |
||
262 |
/** |
|
263 |
* Returns time at given index. |
|
264 |
*/ |
|
265 |
public static long getTimeAtIndex(int index) { |
|
266 |
if (loggingEnabled()) { |
|
51 | 267 |
return times.get(index).getTime(); |
2 | 268 |
} else { |
269 |
return 0; |
|
270 |
} |
|
271 |
} |
|
272 |
||
273 |
/** |
|
274 |
* Returns message at given index. |
|
275 |
*/ |
|
276 |
public static String getMessageAtIndex(int index) { |
|
277 |
if (loggingEnabled()) { |
|
51 | 278 |
return times.get(index).getMessage(); |
2 | 279 |
} else { |
280 |
return null; |
|
281 |
} |
|
282 |
} |
|
283 |
||
284 |
/** |
|
285 |
* Outputs all data to parameter-specified Writer object |
|
286 |
*/ |
|
287 |
public static void outputLog(Writer writer) { |
|
288 |
if (loggingEnabled()) { |
|
289 |
try { |
|
290 |
synchronized(times) { |
|
291 |
for (int i = 0; i < times.size(); ++i) { |
|
51 | 292 |
TimeData td = times.get(i); |
2 | 293 |
if (td != null) { |
294 |
writer.write(i + " " + td.getMessage() + ": " + |
|
3111
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
295 |
(td.getTime() - baseTime) + "\n"); |
fefdeafb7ab9
6797688: Umbrella: Merge all JDK 6u4 - 6u12 deployment code into JDK7
herrick
parents:
715
diff
changeset
|
296 |
|
2 | 297 |
} |
298 |
} |
|
299 |
} |
|
300 |
writer.flush(); |
|
301 |
} catch (Exception e) { |
|
302 |
System.out.println(e + ": Writing performance log to " + |
|
303 |
writer); |
|
304 |
} |
|
305 |
} |
|
306 |
} |
|
307 |
||
308 |
/** |
|
309 |
* Outputs all data to whatever location the user specified |
|
310 |
* via sun.perflog command-line parameter. |
|
311 |
*/ |
|
312 |
public static void outputLog() { |
|
313 |
outputLog(logWriter); |
|
314 |
} |
|
315 |
} |