001/*
002 * Copyright 2002-2019 the original author or authors.
003 *
004 * Licensed under the Apache License, Version 2.0 (the "License");
005 * you may not use this file except in compliance with the License.
006 * You may obtain a copy of the License at
007 *
008 *      https://www.apache.org/licenses/LICENSE-2.0
009 *
010 * Unless required by applicable law or agreed to in writing, software
011 * distributed under the License is distributed on an "AS IS" BASIS,
012 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
013 * See the License for the specific language governing permissions and
014 * limitations under the License.
015 */
016
017package org.springframework.util;
018
019import java.text.NumberFormat;
020import java.util.LinkedList;
021import java.util.List;
022import java.util.concurrent.TimeUnit;
023
024import org.springframework.lang.Nullable;
025
026/**
027 * Simple stop watch, allowing for timing of a number of tasks, exposing total
028 * running time and running time for each named task.
029 *
030 * <p>Conceals use of {@link System#nanoTime()}, improving the readability of
031 * application code and reducing the likelihood of calculation errors.
032 *
033 * <p>Note that this object is not designed to be thread-safe and does not use
034 * synchronization.
035 *
036 * <p>This class is normally used to verify performance during proof-of-concept
037 * work and in development, rather than as part of production applications.
038 *
039 * <p>As of Spring Framework 5.2, running time is tracked and reported in
040 * nanoseconds.
041 *
042 * @author Rod Johnson
043 * @author Juergen Hoeller
044 * @author Sam Brannen
045 * @since May 2, 2001
046 */
047public class StopWatch {
048
049        /**
050         * Identifier of this {@code StopWatch}.
051         * <p>Handy when we have output from multiple stop watches and need to
052         * distinguish between them in log or console output.
053         */
054        private final String id;
055
056        private boolean keepTaskList = true;
057
058        private final List<TaskInfo> taskList = new LinkedList<>();
059
060        /** Start time of the current task. */
061        private long startTimeNanos;
062
063        /** Name of the current task. */
064        @Nullable
065        private String currentTaskName;
066
067        @Nullable
068        private TaskInfo lastTaskInfo;
069
070        private int taskCount;
071
072        /** Total running time. */
073        private long totalTimeNanos;
074
075
076        /**
077         * Construct a new {@code StopWatch}.
078         * <p>Does not start any task.
079         */
080        public StopWatch() {
081                this("");
082        }
083
084        /**
085         * Construct a new {@code StopWatch} with the given ID.
086         * <p>The ID is handy when we have output from multiple stop watches and need
087         * to distinguish between them.
088         * <p>Does not start any task.
089         * @param id identifier for this stop watch
090         */
091        public StopWatch(String id) {
092                this.id = id;
093        }
094
095
096        /**
097         * Get the ID of this {@code StopWatch}, as specified on construction.
098         * @return the ID (empty String by default)
099         * @since 4.2.2
100         * @see #StopWatch(String)
101         */
102        public String getId() {
103                return this.id;
104        }
105
106        /**
107         * Configure whether the {@link TaskInfo} array is built over time.
108         * <p>Set this to {@code false} when using a {@code StopWatch} for millions
109         * of intervals; otherwise, the {@code TaskInfo} structure will consume
110         * excessive memory.
111         * <p>Default is {@code true}.
112         */
113        public void setKeepTaskList(boolean keepTaskList) {
114                this.keepTaskList = keepTaskList;
115        }
116
117
118        /**
119         * Start an unnamed task.
120         * <p>The results are undefined if {@link #stop()} or timing methods are
121         * called without invoking this method first.
122         * @see #start(String)
123         * @see #stop()
124         */
125        public void start() throws IllegalStateException {
126                start("");
127        }
128
129        /**
130         * Start a named task.
131         * <p>The results are undefined if {@link #stop()} or timing methods are
132         * called without invoking this method first.
133         * @param taskName the name of the task to start
134         * @see #start()
135         * @see #stop()
136         */
137        public void start(String taskName) throws IllegalStateException {
138                if (this.currentTaskName != null) {
139                        throw new IllegalStateException("Can't start StopWatch: it's already running");
140                }
141                this.currentTaskName = taskName;
142                this.startTimeNanos = System.nanoTime();
143        }
144
145        /**
146         * Stop the current task.
147         * <p>The results are undefined if timing methods are called without invoking
148         * at least one pair of {@code start()} / {@code stop()} methods.
149         * @see #start()
150         * @see #start(String)
151         */
152        public void stop() throws IllegalStateException {
153                if (this.currentTaskName == null) {
154                        throw new IllegalStateException("Can't stop StopWatch: it's not running");
155                }
156                long lastTime = System.nanoTime() - this.startTimeNanos;
157                this.totalTimeNanos += lastTime;
158                this.lastTaskInfo = new TaskInfo(this.currentTaskName, lastTime);
159                if (this.keepTaskList) {
160                        this.taskList.add(this.lastTaskInfo);
161                }
162                ++this.taskCount;
163                this.currentTaskName = null;
164        }
165
166        /**
167         * Determine whether this {@code StopWatch} is currently running.
168         * @see #currentTaskName()
169         */
170        public boolean isRunning() {
171                return (this.currentTaskName != null);
172        }
173
174        /**
175         * Get the name of the currently running task, if any.
176         * @since 4.2.2
177         * @see #isRunning()
178         */
179        @Nullable
180        public String currentTaskName() {
181                return this.currentTaskName;
182        }
183
184        /**
185         * Get the time taken by the last task in nanoseconds.
186         * @since 5.2
187         * @see #getLastTaskTimeMillis()
188         */
189        public long getLastTaskTimeNanos() throws IllegalStateException {
190                if (this.lastTaskInfo == null) {
191                        throw new IllegalStateException("No tasks run: can't get last task interval");
192                }
193                return this.lastTaskInfo.getTimeNanos();
194        }
195
196        /**
197         * Get the time taken by the last task in milliseconds.
198         * @see #getLastTaskTimeNanos()
199         */
200        public long getLastTaskTimeMillis() throws IllegalStateException {
201                if (this.lastTaskInfo == null) {
202                        throw new IllegalStateException("No tasks run: can't get last task interval");
203                }
204                return this.lastTaskInfo.getTimeMillis();
205        }
206
207        /**
208         * Get the name of the last task.
209         */
210        public String getLastTaskName() throws IllegalStateException {
211                if (this.lastTaskInfo == null) {
212                        throw new IllegalStateException("No tasks run: can't get last task name");
213                }
214                return this.lastTaskInfo.getTaskName();
215        }
216
217        /**
218         * Get the last task as a {@link TaskInfo} object.
219         */
220        public TaskInfo getLastTaskInfo() throws IllegalStateException {
221                if (this.lastTaskInfo == null) {
222                        throw new IllegalStateException("No tasks run: can't get last task info");
223                }
224                return this.lastTaskInfo;
225        }
226
227
228        /**
229         * Get the total time in nanoseconds for all tasks.
230         * @since 5.2
231         * @see #getTotalTimeMillis()
232         * @see #getTotalTimeSeconds()
233         */
234        public long getTotalTimeNanos() {
235                return this.totalTimeNanos;
236        }
237
238        /**
239         * Get the total time in milliseconds for all tasks.
240         * @see #getTotalTimeNanos()
241         * @see #getTotalTimeSeconds()
242         */
243        public long getTotalTimeMillis() {
244                return nanosToMillis(this.totalTimeNanos);
245        }
246
247        /**
248         * Get the total time in seconds for all tasks.
249         * @see #getTotalTimeNanos()
250         * @see #getTotalTimeMillis()
251         */
252        public double getTotalTimeSeconds() {
253                return nanosToSeconds(this.totalTimeNanos);
254        }
255
256        /**
257         * Get the number of tasks timed.
258         */
259        public int getTaskCount() {
260                return this.taskCount;
261        }
262
263        /**
264         * Get an array of the data for tasks performed.
265         */
266        public TaskInfo[] getTaskInfo() {
267                if (!this.keepTaskList) {
268                        throw new UnsupportedOperationException("Task info is not being kept!");
269                }
270                return this.taskList.toArray(new TaskInfo[0]);
271        }
272
273
274        /**
275         * Get a short description of the total running time.
276         */
277        public String shortSummary() {
278                return "StopWatch '" + getId() + "': running time = " + getTotalTimeNanos() + " ns";
279        }
280
281        /**
282         * Generate a string with a table describing all tasks performed.
283         * <p>For custom reporting, call {@link #getTaskInfo()} and use the task info
284         * directly.
285         */
286        public String prettyPrint() {
287                StringBuilder sb = new StringBuilder(shortSummary());
288                sb.append('\n');
289                if (!this.keepTaskList) {
290                        sb.append("No task info kept");
291                }
292                else {
293                        sb.append("---------------------------------------------\n");
294                        sb.append("ns         %     Task name\n");
295                        sb.append("---------------------------------------------\n");
296                        NumberFormat nf = NumberFormat.getNumberInstance();
297                        nf.setMinimumIntegerDigits(9);
298                        nf.setGroupingUsed(false);
299                        NumberFormat pf = NumberFormat.getPercentInstance();
300                        pf.setMinimumIntegerDigits(3);
301                        pf.setGroupingUsed(false);
302                        for (TaskInfo task : getTaskInfo()) {
303                                sb.append(nf.format(task.getTimeNanos())).append("  ");
304                                sb.append(pf.format((double) task.getTimeNanos() / getTotalTimeNanos())).append("  ");
305                                sb.append(task.getTaskName()).append("\n");
306                        }
307                }
308                return sb.toString();
309        }
310
311        /**
312         * Generate an informative string describing all tasks performed
313         * <p>For custom reporting, call {@link #getTaskInfo()} and use the task info
314         * directly.
315         */
316        @Override
317        public String toString() {
318                StringBuilder sb = new StringBuilder(shortSummary());
319                if (this.keepTaskList) {
320                        for (TaskInfo task : getTaskInfo()) {
321                                sb.append("; [").append(task.getTaskName()).append("] took ").append(task.getTimeNanos()).append(" ns");
322                                long percent = Math.round(100.0 * task.getTimeNanos() / getTotalTimeNanos());
323                                sb.append(" = ").append(percent).append("%");
324                        }
325                }
326                else {
327                        sb.append("; no task info kept");
328                }
329                return sb.toString();
330        }
331
332
333        private static long nanosToMillis(long duration) {
334                return TimeUnit.NANOSECONDS.toMillis(duration);
335        }
336
337        private static double nanosToSeconds(long duration) {
338                return duration / 1_000_000_000.0;
339        }
340
341
342        /**
343         * Nested class to hold data about one task executed within the {@code StopWatch}.
344         */
345        public static final class TaskInfo {
346
347                private final String taskName;
348
349                private final long timeNanos;
350
351                TaskInfo(String taskName, long timeNanos) {
352                        this.taskName = taskName;
353                        this.timeNanos = timeNanos;
354                }
355
356                /**
357                 * Get the name of this task.
358                 */
359                public String getTaskName() {
360                        return this.taskName;
361                }
362
363                /**
364                 * Get the time in nanoseconds this task took.
365                 * @since 5.2
366                 * @see #getTimeMillis()
367                 * @see #getTimeSeconds()
368                 */
369                public long getTimeNanos() {
370                        return this.timeNanos;
371                }
372
373                /**
374                 * Get the time in milliseconds this task took.
375                 * @see #getTimeNanos()
376                 * @see #getTimeSeconds()
377                 */
378                public long getTimeMillis() {
379                        return nanosToMillis(this.timeNanos);
380                }
381
382                /**
383                 * Get the time in seconds this task took.
384                 * @see #getTimeMillis()
385                 * @see #getTimeNanos()
386                 */
387                public double getTimeSeconds() {
388                        return nanosToSeconds(this.timeNanos);
389                }
390
391        }
392
393}