001/*
002 * #%L
003 * HAPI FHIR - Core Library
004 * %%
005 * Copyright (C) 2014 - 2024 Smile CDR, Inc.
006 * %%
007 * Licensed under the Apache License, Version 2.0 (the "License");
008 * you may not use this file except in compliance with the License.
009 * You may obtain a copy of the License at
010 *
011 * http://www.apache.org/licenses/LICENSE-2.0
012 *
013 * Unless required by applicable law or agreed to in writing, software
014 * distributed under the License is distributed on an "AS IS" BASIS,
015 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
016 * See the License for the specific language governing permissions and
017 * limitations under the License.
018 * #L%
019 */
020package ca.uhn.fhir.util;
021
022import com.google.common.annotations.VisibleForTesting;
023import org.apache.commons.lang3.Validate;
024import org.apache.commons.lang3.time.DateUtils;
025
026import java.text.DecimalFormat;
027import java.text.NumberFormat;
028import java.util.Date;
029import java.util.LinkedList;
030import java.util.concurrent.TimeUnit;
031
032/**
033 * A multipurpose stopwatch which can be used to time tasks and produce
034 * human readable output about task duration, throughput, estimated task completion,
035 * etc.
036 * <p>
037 * <p>
038 * <b>Thread Safety Note: </b> StopWatch is not intended to be thread safe.
039 * </p>
040 *
041 * @since HAPI FHIR 3.3.0
042 */
043public class StopWatch {
044
045        // TODO KHS it is risky for this to be a static field.  Safer to make it non-static, but that will require
046        // TODO KHS significant rework of StopWatchTest
047        private static Long ourNowForUnitTest;
048        private long myStarted = now();
049        private TaskTiming myCurrentTask;
050        private LinkedList<TaskTiming> myTasks;
051
052        /**
053         * Constructor
054         */
055        public StopWatch() {
056                super();
057        }
058
059        /**
060         * Constructor
061         *
062         * @param theStart The time to record as the start for this timer
063         */
064        public StopWatch(Date theStart) {
065                myStarted = theStart.getTime();
066        }
067
068        /**
069         * Constructor
070         *
071         * @param theStart The time that the stopwatch was started
072         */
073        public StopWatch(long theStart) {
074                myStarted = theStart;
075        }
076
077        private void addNewlineIfContentExists(StringBuilder theB) {
078                if (theB.length() > 0) {
079                        theB.append("\n");
080                }
081        }
082
083        /**
084         * Finish the counter on the current task (which was started by calling
085         * {@link #startTask(String)}. This method has no effect if no task
086         * is currently started so it's ok to call it more than once.
087         */
088        public void endCurrentTask() {
089                ensureTasksListExists();
090                if (myCurrentTask != null) {
091                        myCurrentTask.setEnd(now());
092                }
093                myCurrentTask = null;
094        }
095
096        private void ensureTasksListExists() {
097                if (myTasks == null) {
098                        myTasks = new LinkedList<>();
099                }
100        }
101
102        /**
103         * Returns a nice human-readable display of the time taken per
104         * operation. Note that this may not actually output the number
105         * of milliseconds if the time taken per operation was very long (over
106         * 10 seconds)
107         *
108         * @see #formatMillis(long)
109         */
110        public String formatMillisPerOperation(long theNumOperations) {
111                double millisPerOperation = (((double) getMillis()) / Math.max(1.0, theNumOperations));
112                return formatMillis(millisPerOperation);
113        }
114
115        /**
116         * Returns a string providing the durations of all tasks collected by {@link #startTask(String)}
117         */
118        public String formatTaskDurations() {
119
120                ensureTasksListExists();
121                StringBuilder b = new StringBuilder();
122
123                if (myTasks.size() > 0) {
124                        long delta = myTasks.getFirst().getStart() - myStarted;
125                        if (delta > 10) {
126                                addNewlineIfContentExists(b);
127                                b.append("Before first task");
128                                b.append(": ");
129                                b.append(formatMillis(delta));
130                        }
131                } else {
132                        b.append("No tasks");
133                }
134
135                TaskTiming last = null;
136                for (TaskTiming nextTask : myTasks) {
137
138                        if (last != null) {
139                                long delta = nextTask.getStart() - last.getEnd();
140                                if (delta > 10) {
141                                        addNewlineIfContentExists(b);
142                                        b.append("Between");
143                                        b.append(": ");
144                                        b.append(formatMillis(delta));
145                                }
146                        }
147
148                        addNewlineIfContentExists(b);
149                        b.append(nextTask.getTaskName());
150                        b.append(": ");
151                        long delta = nextTask.getMillis();
152                        b.append(formatMillis(delta));
153
154                        last = nextTask;
155                }
156
157                if (myTasks.size() > 0) {
158                        long delta = now() - myTasks.getLast().getEnd();
159                        if (delta > 10) {
160                                addNewlineIfContentExists(b);
161                                b.append("After last task");
162                                b.append(": ");
163                                b.append(formatMillis(delta));
164                        }
165                }
166
167                return b.toString();
168        }
169
170        /**
171         * Determine the current throughput per unit of time (specified in theUnit)
172         * assuming that theNumOperations operations have happened.
173         * <p>
174         * For example, if this stopwatch has 2 seconds elapsed, and this method is
175         * called for theNumOperations=30 and TimeUnit=SECONDS,
176         * this method will return 15
177         * </p>
178         *
179         * @see #getThroughput(long, TimeUnit)
180         */
181        public String formatThroughput(long theNumOperations, TimeUnit theUnit) {
182                double throughput = getThroughput(theNumOperations, theUnit);
183                return formatThroughput(throughput);
184        }
185
186        /**
187         * Given an amount of something completed so far, and a total amount, calculates how long it will take for something to complete
188         *
189         * @param theCompleteToDate The amount so far
190         * @param theTotal          The total (must be higher than theCompleteToDate
191         * @return A formatted amount of time
192         */
193        public String getEstimatedTimeRemaining(double theCompleteToDate, double theTotal) {
194                double millis = getMillis();
195                return formatEstimatedTimeRemaining(theCompleteToDate, theTotal, millis);
196        }
197
198        /**
199         * Given an amount of something completed so far, and a total amount, calculates how long it will take for something to complete
200         *
201         * @param theCompleteToDate The amount so far
202         * @param theTotal          The total (must be higher than theCompleteToDate
203         * @return A formatted amount of time
204         */
205        public static String formatEstimatedTimeRemaining(double theCompleteToDate, double theTotal, double millis) {
206                long millisRemaining = (long) (((theTotal / theCompleteToDate) * millis) - millis);
207                return formatMillis(millisRemaining);
208        }
209
210        public long getMillis(Date theNow) {
211                return theNow.getTime() - myStarted;
212        }
213
214        public long getMillis() {
215                long now = now();
216                return now - myStarted;
217        }
218
219        public long getMillisAndRestart() {
220                long now = now();
221                long retVal = now - myStarted;
222                myStarted = now;
223                return retVal;
224        }
225
226        /**
227         * @param theNumOperations Ok for this to be 0, it will be treated as 1
228         */
229        public long getMillisPerOperation(long theNumOperations) {
230                return (long) (((double) getMillis()) / Math.max(1.0, theNumOperations));
231        }
232
233        public Date getStartedDate() {
234                return new Date(myStarted);
235        }
236
237        /**
238         * Determine the current throughput per unit of time (specified in theUnit)
239         * assuming that theNumOperations operations have happened.
240         * <p>
241         * For example, if this stopwatch has 2 seconds elapsed, and this method is
242         * called for theNumOperations=30 and TimeUnit=SECONDS,
243         * this method will return 15
244         * </p>
245         *
246         * @see #formatThroughput(long, TimeUnit)
247         */
248        public double getThroughput(long theNumOperations, TimeUnit theUnit) {
249                long millis = getMillis();
250                return getThroughput(theNumOperations, millis, theUnit);
251        }
252
253        public void restart() {
254                myStarted = now();
255        }
256
257        /**
258         * Starts a counter for a sub-task
259         * <p>
260         * <b>Thread Safety Note: </b> This method is not threadsafe! Do not use subtasks in a
261         * multithreaded environment.
262         * </p>
263         *
264         * @param theTaskName Note that if theTaskName is blank or empty, no task is started
265         */
266        public void startTask(String theTaskName) {
267                endCurrentTask();
268                Validate.notBlank(theTaskName, "Task name must not be blank");
269                myCurrentTask = new TaskTiming().setTaskName(theTaskName).setStart(now());
270                myTasks.add(myCurrentTask);
271        }
272
273        /**
274         * Formats value in an appropriate format. See {@link #formatMillis(long)}}
275         * for a description of the format
276         *
277         * @see #formatMillis(long)
278         */
279        @Override
280        public String toString() {
281                return formatMillis(getMillis());
282        }
283
284        /**
285         * Format a throughput number (output does not include units)
286         */
287        public static String formatThroughput(double throughput) {
288                return new DecimalFormat("0.0").format(throughput);
289        }
290
291        /**
292         * Calculate throughput
293         *
294         * @param theNumOperations The number of operations completed
295         * @param theMillisElapsed The time elapsed
296         * @param theUnit          The unit for the throughput
297         */
298        public static double getThroughput(long theNumOperations, long theMillisElapsed, TimeUnit theUnit) {
299                if (theNumOperations <= 0) {
300                        return 0.0f;
301                }
302                long millisElapsed = Math.max(1, theMillisElapsed);
303                long periodMillis = theUnit.toMillis(1);
304
305                double denominator = ((double) millisElapsed) / ((double) periodMillis);
306
307                double throughput = (double) theNumOperations / denominator;
308                if (throughput > theNumOperations) {
309                        throughput = theNumOperations;
310                }
311
312                return throughput;
313        }
314
315        private static NumberFormat getDayFormat() {
316                return new DecimalFormat("0.0");
317        }
318
319        private static NumberFormat getTenDayFormat() {
320                return new DecimalFormat("0");
321        }
322
323        private static NumberFormat getSubMillisecondMillisFormat() {
324                return new DecimalFormat("0.000");
325        }
326
327        /**
328         * Append a right-aligned and zero-padded numeric value to a `StringBuilder`.
329         */
330        static void appendRightAlignedNumber(
331                        StringBuilder theStringBuilder, String thePrefix, int theNumberOfDigits, long theValueToAppend) {
332                theStringBuilder.append(thePrefix);
333                if (theNumberOfDigits > 1) {
334                        int pad = (theNumberOfDigits - 1);
335                        for (long xa = theValueToAppend; xa > 9 && pad > 0; xa /= 10) {
336                                pad--;
337                        }
338                        for (int xa = 0; xa < pad; xa++) {
339                                theStringBuilder.append('0');
340                        }
341                }
342                theStringBuilder.append(theValueToAppend);
343        }
344
345        /**
346         * Formats a number of milliseconds for display (e.g.
347         * in a log file), tailoring the output to how big
348         * the value actually is.
349         * <p>
350         * Example outputs:
351         * </p>
352         * <ul>
353         * <li>133ms</li>
354         * <li>00:00:10.223</li>
355         * <li>1.7 days</li>
356         * <li>64 days</li>
357         * </ul>
358         */
359        public static String formatMillis(long theMillis) {
360                return formatMillis((double) theMillis);
361        }
362
363        /**
364         * Formats a number of milliseconds for display (e.g.
365         * in a log file), tailoring the output to how big
366         * the value actually is.
367         * <p>
368         * Example outputs:
369         * </p>
370         * <ul>
371         * <li>133ms</li>
372         * <li>00:00:10.223</li>
373         * <li>1.7 days</li>
374         * <li>64 days</li>
375         * </ul>
376         */
377        public static String formatMillis(double theMillis) {
378                StringBuilder buf = new StringBuilder(20);
379                if (theMillis > 0.0 && theMillis < 1.0) {
380                        buf.append(getSubMillisecondMillisFormat().format(theMillis));
381                        buf.append("ms");
382                } else if (theMillis < (10 * DateUtils.MILLIS_PER_SECOND)) {
383                        buf.append((int) theMillis);
384                        buf.append("ms");
385                } else if (theMillis >= DateUtils.MILLIS_PER_DAY) {
386                        double days = theMillis / DateUtils.MILLIS_PER_DAY;
387                        if (days >= 10) {
388                                buf.append(getTenDayFormat().format(days));
389                                buf.append(" days");
390                        } else if (days != 1.0f) {
391                                buf.append(getDayFormat().format(days));
392                                buf.append(" days");
393                        } else {
394                                buf.append(getDayFormat().format(days));
395                                buf.append(" day");
396                        }
397                } else {
398                        long millisAsLong = (long) theMillis;
399                        appendRightAlignedNumber(
400                                        buf, "", 2, ((millisAsLong % DateUtils.MILLIS_PER_DAY) / DateUtils.MILLIS_PER_HOUR));
401                        appendRightAlignedNumber(
402                                        buf, ":", 2, ((millisAsLong % DateUtils.MILLIS_PER_HOUR) / DateUtils.MILLIS_PER_MINUTE));
403                        appendRightAlignedNumber(
404                                        buf, ":", 2, ((millisAsLong % DateUtils.MILLIS_PER_MINUTE) / DateUtils.MILLIS_PER_SECOND));
405                        if (theMillis <= DateUtils.MILLIS_PER_MINUTE) {
406                                appendRightAlignedNumber(buf, ".", 3, (millisAsLong % DateUtils.MILLIS_PER_SECOND));
407                        }
408                }
409                return buf.toString();
410        }
411
412        private static long now() {
413                if (ourNowForUnitTest != null) {
414                        return ourNowForUnitTest;
415                }
416                return System.currentTimeMillis();
417        }
418
419        @VisibleForTesting
420        public static void setNowForUnitTest(Long theNowForUnitTest) {
421                ourNowForUnitTest = theNowForUnitTest;
422        }
423
424        private static class TaskTiming {
425                private long myStart;
426                private long myEnd;
427                private String myTaskName;
428
429                public long getEnd() {
430                        if (myEnd == 0) {
431                                return now();
432                        }
433                        return myEnd;
434                }
435
436                public TaskTiming setEnd(long theEnd) {
437                        myEnd = theEnd;
438                        return this;
439                }
440
441                public long getMillis() {
442                        return getEnd() - getStart();
443                }
444
445                public long getStart() {
446                        return myStart;
447                }
448
449                public TaskTiming setStart(long theStart) {
450                        myStart = theStart;
451                        return this;
452                }
453
454                public String getTaskName() {
455                        return myTaskName;
456                }
457
458                public TaskTiming setTaskName(String theTaskName) {
459                        myTaskName = theTaskName;
460                        return this;
461                }
462        }
463}