J. Duke | 319a3b9 | 2007-12-01 00:00:00 +0000 | [diff] [blame^] | 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 | } |