001: /*
002: * Copyright 2002 Sun Microsystems, Inc. All Rights Reserved.
003: * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
004: *
005: * This code is free software; you can redistribute it and/or modify it
006: * under the terms of the GNU General Public License version 2 only, as
007: * published by the Free Software Foundation. Sun designates this
008: * particular file as subject to the "Classpath" exception as provided
009: * by Sun in the LICENSE file that accompanied this code.
010: *
011: * This code is distributed in the hope that it will be useful, but WITHOUT
012: * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
013: * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
014: * version 2 for more details (a copy is included in the LICENSE file that
015: * accompanied this code).
016: *
017: * You should have received a copy of the GNU General Public License version
018: * 2 along with this work; if not, write to the Free Software Foundation,
019: * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
020: *
021: * Please contact Sun Microsystems, Inc., 4150 Network Circle, Santa Clara,
022: * CA 95054 USA or visit www.sun.com if you need additional information or
023: * have any questions.
024: */
025:
026: package sun.misc;
027:
028: import java.util.Vector;
029: import java.io.FileWriter;
030: import java.io.File;
031: import java.io.OutputStreamWriter;
032: import java.io.Writer;
033:
034: /**
035: * This class is intended to be a central place for the jdk to
036: * log timing events of interest. There is pre-defined event
037: * of startTime, as well as a general
038: * mechanism of setting aribtrary times in an array.
039: * All unreserved times in the array can be used by callers
040: * in application-defined situations. The caller is responsible
041: * for setting and getting all times and for doing whatever
042: * analysis is interesting; this class is merely a central container
043: * for those timing values.
044: * Note that, due to the variables in this class being static,
045: * use of particular time values by multiple applets will cause
046: * confusing results. For example, if plugin runs two applets
047: * simultaneously, the initTime for those applets will collide
048: * and the results may be undefined.
049: * <P>
050: * To automatically track startup performance in an app or applet,
051: * use the command-line parameter sun.perflog as follows:<BR>
052: * -Dsun.perflog[=file:<filename>]
053: * <BR>
054: * where simply using the parameter with no value will enable output
055: * to the console and a value of "file:<filename>" will cause
056: * that given filename to be created and used for all output.
057: * <P>
058: * By default, times are measured using System.currentTimeMillis(). To use
059: * System.nanoTime() instead, add the command-line parameter:<BR>
060: -Dsun.perflog.nano=true
061: * <BR>
062: * <P>
063: * <B>Warning: Use at your own risk!</B>
064: * This class is intended for internal testing
065: * purposes only and may be removed at any time. More
066: * permanent monitoring and profiling APIs are expected to be
067: * developed for future releases and this class will cease to
068: * exist once those APIs are in place.
069: * @author Chet Haase
070: */
071: public class PerformanceLogger {
072:
073: // Timing values of global interest
074: private static final int START_INDEX = 0; // VM start
075: private static final int LAST_RESERVED = START_INDEX;
076:
077: private static boolean perfLoggingOn = false;
078: private static boolean useNanoTime = false;
079: private static Vector times;
080: private static String logFileName = null;
081: private static Writer logWriter = null;
082:
083: static {
084: String perfLoggingProp = (String) java.security.AccessController
085: .doPrivileged(new sun.security.action.GetPropertyAction(
086: "sun.perflog"));
087: if (perfLoggingProp != null) {
088: perfLoggingOn = true;
089:
090: // Check if we should use nanoTime
091: String perfNanoProp = (String) java.security.AccessController
092: .doPrivileged(new sun.security.action.GetPropertyAction(
093: "sun.perflog.nano"));
094: if (perfNanoProp != null) {
095: useNanoTime = true;
096: }
097:
098: // Now, figure out what the user wants to do with the data
099: if (perfLoggingProp.regionMatches(true, 0, "file:", 0, 5)) {
100: logFileName = perfLoggingProp.substring(5);
101: }
102: if (logFileName != null) {
103: if (logWriter == null) {
104: java.security.AccessController
105: .doPrivileged(new java.security.PrivilegedAction() {
106: public Object run() {
107: try {
108: File logFile = new File(
109: logFileName);
110: logFile.createNewFile();
111: logWriter = new FileWriter(
112: logFile);
113: } catch (Exception e) {
114: System.out.println(e
115: + ": 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: }
128: times = new Vector(10);
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: * 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: }
|