1/*
2 * Copyright (c) 2002, 2013, 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
27
28package sun.awt.util;
29
30import java.util.Vector;
31import java.io.FileWriter;
32import java.io.File;
33import java.io.OutputStreamWriter;
34import 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 arbitrary 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 * <pre>{@code
55 *     -Dsun.perflog[=file:<filename>]
56 * }</pre>
57 * <BR>
58 * where simply using the parameter with no value will enable output
59 * to the console and a value of "{@code file:<filename>}" will cause
60 * that given filename to be created and used for all output.
61 * <P>
62 * By default, times are measured using System.currentTimeMillis().  To use
63 * System.nanoTime() instead, add the command-line parameter:<BR>
64       -Dsun.perflog.nano=true
65 * <BR>
66 * <P>
67 * <B>Warning: Use at your own risk!</B>
68 * This class is intended for internal testing
69 * purposes only and may be removed at any time.  More
70 * permanent monitoring and profiling APIs are expected to be
71 * developed for future releases and this class will cease to
72 * exist once those APIs are in place.
73 * @author Chet Haase
74 */
75public class PerformanceLogger {
76
77    // Timing values of global interest
78    private static final int START_INDEX    = 0;    // VM start
79    private static final int LAST_RESERVED  = START_INDEX;
80
81    private static boolean perfLoggingOn = false;
82    private static boolean useNanoTime = false;
83    private static Vector<TimeData> times;
84    private static String logFileName = null;
85    private static Writer logWriter = null;
86    private static long baseTime;
87
88    static {
89        String perfLoggingProp =
90            java.security.AccessController.doPrivileged(
91            new sun.security.action.GetPropertyAction("sun.perflog"));
92        if (perfLoggingProp != null) {
93            perfLoggingOn = true;
94
95            // Check if we should use nanoTime
96            String perfNanoProp =
97                java.security.AccessController.doPrivileged(
98                new sun.security.action.GetPropertyAction("sun.perflog.nano"));
99            if (perfNanoProp != null) {
100                useNanoTime = true;
101            }
102
103            // Now, figure out what the user wants to do with the data
104            if (perfLoggingProp.regionMatches(true, 0, "file:", 0, 5)) {
105                logFileName = perfLoggingProp.substring(5);
106            }
107            if (logFileName != null) {
108                if (logWriter == null) {
109                    java.security.AccessController.doPrivileged(
110                    new java.security.PrivilegedAction<Void>() {
111                        public Void run() {
112                            try {
113                                File logFile = new File(logFileName);
114                                logFile.createNewFile();
115                                logWriter = new FileWriter(logFile);
116                            } catch (Exception e) {
117                                System.out.println(e + ": Creating logfile " +
118                                                   logFileName +
119                                                   ".  Log to console");
120                            }
121                            return null;
122                        }
123                    });
124                }
125            }
126            if (logWriter == null) {
127                logWriter = new OutputStreamWriter(System.out);
128            }
129        }
130        times = new Vector<TimeData>(10);
131        // Reserve predefined slots
132        for (int i = 0; i <= LAST_RESERVED; ++i) {
133            times.add(new TimeData("Time " + i + " not set", 0));
134        }
135    }
136
137    /**
138     * Returns status of whether logging is enabled or not.  This is
139     * provided as a convenience method so that users do not have to
140     * perform the same GetPropertyAction check as above to determine whether
141     * to enable performance logging.
142     */
143    public static boolean loggingEnabled() {
144        return perfLoggingOn;
145    }
146
147
148    /**
149     * Internal class used to store time/message data together.
150     */
151    static class TimeData {
152        String message;
153        long time;
154
155        TimeData(String message, long time) {
156            this.message = message;
157            this.time = time;
158        }
159
160        String getMessage() {
161            return message;
162        }
163
164        long getTime() {
165            return time;
166        }
167    }
168
169    /**
170     * Return the current time, in millis or nanos as appropriate
171     */
172    private static long getCurrentTime() {
173        if (useNanoTime) {
174            return System.nanoTime();
175        } else {
176            return System.currentTimeMillis();
177        }
178    }
179
180    /**
181     * Sets the start time.  Ideally, this is the earliest time available
182     * during the startup of a Java applet or application.  This time is
183     * later used to analyze the difference between the initial startup
184     * time and other events in the system (such as an applet's init time).
185     */
186    public static void setStartTime(String message) {
187        if (loggingEnabled()) {
188            long nowTime = getCurrentTime();
189            setStartTime(message, nowTime);
190        }
191    }
192
193    /**
194     * Sets the base time, output can then
195     * be displayed as offsets from the base time;.
196     */
197    public static void setBaseTime(long time) {
198        if (loggingEnabled()) {
199            baseTime = time;
200        }
201    }
202
203    /**
204     * Sets the start time.
205     * This version of the method is
206     * given the time to log, instead of expecting this method to
207     * get the time itself.  This is done in case the time was
208     * recorded much earlier than this method was called.
209     */
210    public static void setStartTime(String message, long time) {
211        if (loggingEnabled()) {
212            times.set(START_INDEX, new TimeData(message, time));
213        }
214    }
215
216    /**
217     * Gets the start time, which should be the time when
218     * the java process started, prior to the VM actually being
219     * loaded.
220     */
221    public static long getStartTime() {
222        if (loggingEnabled()) {
223            return times.get(START_INDEX).getTime();
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     */
233    public static int setTime(String message) {
234        if (loggingEnabled()) {
235            long nowTime = getCurrentTime();
236            return setTime(message, nowTime);
237        } else {
238            return 0;
239        }
240    }
241
242    /**
243     * Sets the value of a given time and returns the index of the
244     * slot that that time was stored in.
245     * This version of the method is
246     * given the time to log, instead of expecting this method to
247     * get the time itself.  This is done in case the time was
248     * recorded much earlier than this method was called.
249     */
250    public static int setTime(String message, long time) {
251        if (loggingEnabled()) {
252            // times is already synchronized, but we need to ensure that
253            // the size used in times.set() is the same used when returning
254            // the index of that operation.
255            synchronized (times) {
256                times.add(new TimeData(message, time));
257                return (times.size() - 1);
258            }
259        } else {
260            return 0;
261        }
262    }
263
264    /**
265     * Returns time at given index.
266     */
267    public static long getTimeAtIndex(int index) {
268        if (loggingEnabled()) {
269            return times.get(index).getTime();
270        } else {
271            return 0;
272        }
273    }
274
275    /**
276     * Returns message at given index.
277     */
278    public static String getMessageAtIndex(int index) {
279        if (loggingEnabled()) {
280            return times.get(index).getMessage();
281        } else {
282            return null;
283        }
284    }
285
286    /**
287     * Outputs all data to parameter-specified Writer object
288     */
289    public static void outputLog(Writer writer) {
290        if (loggingEnabled()) {
291            try {
292                synchronized(times) {
293                    for (int i = 0; i < times.size(); ++i) {
294                        TimeData td = times.get(i);
295                        if (td != null) {
296                            writer.write(i + " " + td.getMessage() + ": " +
297                                         (td.getTime() - baseTime) + "\n");
298
299                        }
300                    }
301                }
302                writer.flush();
303            } catch (Exception e) {
304                System.out.println(e + ": Writing performance log to " +
305                                   writer);
306            }
307        }
308    }
309
310    /**
311     * Outputs all data to whatever location the user specified
312     * via sun.perflog command-line parameter.
313     */
314    public static void outputLog() {
315        outputLog(logWriter);
316    }
317}
318