2
|
1 |
/*
|
|
2 |
* Copyright 2002 Sun Microsystems, Inc. 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. 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;
|
|
81 |
private static Vector times;
|
|
82 |
private static String logFileName = null;
|
|
83 |
private static Writer logWriter = null;
|
|
84 |
|
|
85 |
static {
|
|
86 |
String perfLoggingProp =
|
|
87 |
java.security.AccessController.doPrivileged(
|
|
88 |
new sun.security.action.GetPropertyAction("sun.perflog"));
|
|
89 |
if (perfLoggingProp != null) {
|
|
90 |
perfLoggingOn = true;
|
|
91 |
|
|
92 |
// Check if we should use nanoTime
|
|
93 |
String perfNanoProp =
|
|
94 |
java.security.AccessController.doPrivileged(
|
|
95 |
new sun.security.action.GetPropertyAction("sun.perflog.nano"));
|
|
96 |
if (perfNanoProp != null) {
|
|
97 |
useNanoTime = true;
|
|
98 |
}
|
|
99 |
|
|
100 |
// Now, figure out what the user wants to do with the data
|
|
101 |
if (perfLoggingProp.regionMatches(true, 0, "file:", 0, 5)) {
|
|
102 |
logFileName = perfLoggingProp.substring(5);
|
|
103 |
}
|
|
104 |
if (logFileName != null) {
|
|
105 |
if (logWriter == null) {
|
|
106 |
java.security.AccessController.doPrivileged(
|
|
107 |
new java.security.PrivilegedAction() {
|
|
108 |
public Object run() {
|
|
109 |
try {
|
|
110 |
File logFile = new File(logFileName);
|
|
111 |
logFile.createNewFile();
|
|
112 |
logWriter = new FileWriter(logFile);
|
|
113 |
} catch (Exception e) {
|
|
114 |
System.out.println(e + ": Creating logfile " +
|
|
115 |
logFileName +
|
|
116 |
". Log to console");
|
|
117 |
}
|
|
118 |
return null;
|
|
119 |
}
|
|
120 |
});
|
|
121 |
}
|
|
122 |
}
|
|
123 |
if (logWriter == null) {
|
|
124 |
logWriter = new OutputStreamWriter(System.out);
|
|
125 |
}
|
|
126 |
}
|
|
127 |
times = new Vector(10);
|
|
128 |
// Reserve predefined slots
|
|
129 |
for (int i = 0; i <= LAST_RESERVED; ++i) {
|
|
130 |
times.add(new TimeData("Time " + i + " not set", 0));
|
|
131 |
}
|
|
132 |
}
|
|
133 |
|
|
134 |
/**
|
|
135 |
* Returns status of whether logging is enabled or not. This is
|
|
136 |
* provided as a convenience method so that users do not have to
|
|
137 |
* perform the same GetPropertyAction check as above to determine whether
|
|
138 |
* to enable performance logging.
|
|
139 |
*/
|
|
140 |
public static boolean loggingEnabled() {
|
|
141 |
return perfLoggingOn;
|
|
142 |
}
|
|
143 |
|
|
144 |
|
|
145 |
/**
|
|
146 |
* Internal class used to store time/message data together.
|
|
147 |
*/
|
|
148 |
static class TimeData {
|
|
149 |
String message;
|
|
150 |
long time;
|
|
151 |
|
|
152 |
TimeData(String message, long time) {
|
|
153 |
this.message = message;
|
|
154 |
this.time = time;
|
|
155 |
}
|
|
156 |
|
|
157 |
String getMessage() {
|
|
158 |
return message;
|
|
159 |
}
|
|
160 |
|
|
161 |
long getTime() {
|
|
162 |
return time;
|
|
163 |
}
|
|
164 |
}
|
|
165 |
|
|
166 |
/**
|
|
167 |
* Return the current time, in millis or nanos as appropriate
|
|
168 |
*/
|
|
169 |
private static long getCurrentTime() {
|
|
170 |
if (useNanoTime) {
|
|
171 |
return System.nanoTime();
|
|
172 |
} else {
|
|
173 |
return System.currentTimeMillis();
|
|
174 |
}
|
|
175 |
}
|
|
176 |
|
|
177 |
/**
|
|
178 |
* Sets the start time. Ideally, this is the earliest time available
|
|
179 |
* during the startup of a Java applet or application. This time is
|
|
180 |
* later used to analyze the difference between the initial startup
|
|
181 |
* time and other events in the system (such as an applet's init time).
|
|
182 |
*/
|
|
183 |
public static void setStartTime(String message) {
|
|
184 |
if (loggingEnabled()) {
|
|
185 |
long nowTime = getCurrentTime();
|
|
186 |
setStartTime(message, nowTime);
|
|
187 |
}
|
|
188 |
}
|
|
189 |
|
|
190 |
/**
|
|
191 |
* Sets the start time.
|
|
192 |
* This version of the method is
|
|
193 |
* given the time to log, instead of expecting this method to
|
|
194 |
* get the time itself. This is done in case the time was
|
|
195 |
* recorded much earlier than this method was called.
|
|
196 |
*/
|
|
197 |
public static void setStartTime(String message, long time) {
|
|
198 |
if (loggingEnabled()) {
|
|
199 |
times.set(START_INDEX, new TimeData(message, time));
|
|
200 |
}
|
|
201 |
}
|
|
202 |
|
|
203 |
/**
|
|
204 |
* Gets the start time, which should be the time when
|
|
205 |
* the java process started, prior to the VM actually being
|
|
206 |
* loaded.
|
|
207 |
*/
|
|
208 |
public static long getStartTime() {
|
|
209 |
if (loggingEnabled()) {
|
|
210 |
return ((TimeData)times.get(START_INDEX)).getTime();
|
|
211 |
} else {
|
|
212 |
return 0;
|
|
213 |
}
|
|
214 |
}
|
|
215 |
|
|
216 |
/**
|
|
217 |
* Sets the value of a given time and returns the index of the
|
|
218 |
* slot that that time was stored in.
|
|
219 |
*/
|
|
220 |
public static int setTime(String message) {
|
|
221 |
if (loggingEnabled()) {
|
|
222 |
long nowTime = getCurrentTime();
|
|
223 |
return setTime(message, nowTime);
|
|
224 |
} else {
|
|
225 |
return 0;
|
|
226 |
}
|
|
227 |
}
|
|
228 |
|
|
229 |
/**
|
|
230 |
* Sets the value of a given time and returns the index of the
|
|
231 |
* slot that that time was stored in.
|
|
232 |
* This version of the method is
|
|
233 |
* given the time to log, instead of expecting this method to
|
|
234 |
* get the time itself. This is done in case the time was
|
|
235 |
* recorded much earlier than this method was called.
|
|
236 |
*/
|
|
237 |
public static int setTime(String message, long time) {
|
|
238 |
if (loggingEnabled()) {
|
|
239 |
// times is already synchronized, but we need to ensure that
|
|
240 |
// the size used in times.set() is the same used when returning
|
|
241 |
// the index of that operation.
|
|
242 |
synchronized (times) {
|
|
243 |
times.add(new TimeData(message, time));
|
|
244 |
return (times.size() - 1);
|
|
245 |
}
|
|
246 |
} else {
|
|
247 |
return 0;
|
|
248 |
}
|
|
249 |
}
|
|
250 |
|
|
251 |
/**
|
|
252 |
* Returns time at given index.
|
|
253 |
*/
|
|
254 |
public static long getTimeAtIndex(int index) {
|
|
255 |
if (loggingEnabled()) {
|
|
256 |
return ((TimeData)times.get(index)).getTime();
|
|
257 |
} else {
|
|
258 |
return 0;
|
|
259 |
}
|
|
260 |
}
|
|
261 |
|
|
262 |
/**
|
|
263 |
* Returns message at given index.
|
|
264 |
*/
|
|
265 |
public static String getMessageAtIndex(int index) {
|
|
266 |
if (loggingEnabled()) {
|
|
267 |
return ((TimeData)times.get(index)).getMessage();
|
|
268 |
} else {
|
|
269 |
return null;
|
|
270 |
}
|
|
271 |
}
|
|
272 |
|
|
273 |
/**
|
|
274 |
* Outputs all data to parameter-specified Writer object
|
|
275 |
*/
|
|
276 |
public static void outputLog(Writer writer) {
|
|
277 |
if (loggingEnabled()) {
|
|
278 |
try {
|
|
279 |
synchronized(times) {
|
|
280 |
for (int i = 0; i < times.size(); ++i) {
|
|
281 |
TimeData td = (TimeData)times.get(i);
|
|
282 |
if (td != null) {
|
|
283 |
writer.write(i + " " + td.getMessage() + ": " +
|
|
284 |
td.getTime() + "\n");
|
|
285 |
}
|
|
286 |
}
|
|
287 |
}
|
|
288 |
writer.flush();
|
|
289 |
} catch (Exception e) {
|
|
290 |
System.out.println(e + ": Writing performance log to " +
|
|
291 |
writer);
|
|
292 |
}
|
|
293 |
}
|
|
294 |
}
|
|
295 |
|
|
296 |
/**
|
|
297 |
* Outputs all data to whatever location the user specified
|
|
298 |
* via sun.perflog command-line parameter.
|
|
299 |
*/
|
|
300 |
public static void outputLog() {
|
|
301 |
outputLog(logWriter);
|
|
302 |
}
|
|
303 |
}
|