001/*
002 * #%L
003 * HAPI FHIR - Core Library
004 * %%
005 * Copyright (C) 2014 - 2025 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) into
286         * a number suitable for logging.
287         * <p>
288         * This method tries to use a suitable amount of precision for logging.
289         * For numbers above 1000 it includes no decimal.
290         * For numbers between 100 and 1000 it includes one decimal.
291         * For numbers below 100 it includes two decimals.
292         * </p>
293         */
294        public static String formatThroughput(double throughput) {
295                return formatDouble(throughput);
296        }
297
298        /**
299         * This method tries to use a suitable amount of precision for logging.
300         * For numbers above 1000 it includes no decimal.
301         * For numbers between 100 and 1000 it includes one decimal.
302         * For numbers below 100 it includes two decimals.
303         */
304        static String formatDouble(double theDouble) {
305                double abs = Math.abs(theDouble);
306                if (abs > 1000) {
307                        return Long.toString(Math.round(theDouble));
308                }
309                if (abs > 100) {
310                        return Double.toString(Math.round(theDouble * 10.0) / 10.0);
311                }
312                return Double.toString(Math.round(theDouble * 100.0) / 100.0);
313        }
314
315        /**
316         * Calculate throughput
317         *
318         * @param theNumOperations The number of operations completed
319         * @param theMillisElapsed The time elapsed
320         * @param theUnit          The unit for the throughput
321         */
322        public static double getThroughput(long theNumOperations, long theMillisElapsed, TimeUnit theUnit) {
323                if (theNumOperations <= 0) {
324                        return 0.0f;
325                }
326                long millisElapsed = Math.max(1, theMillisElapsed);
327                long periodMillis = theUnit.toMillis(1);
328
329                double denominator = ((double) millisElapsed) / ((double) periodMillis);
330
331                double throughput = (double) theNumOperations / denominator;
332                if (throughput > theNumOperations) {
333                        throughput = theNumOperations;
334                }
335
336                return throughput;
337        }
338
339        private static NumberFormat getDayFormat() {
340                return new DecimalFormat("0.0");
341        }
342
343        private static NumberFormat getTenDayFormat() {
344                return new DecimalFormat("0");
345        }
346
347        private static NumberFormat getSubMillisecondMillisFormat() {
348                return new DecimalFormat("0.000");
349        }
350
351        /**
352         * Append a right-aligned and zero-padded numeric value to a `StringBuilder`.
353         */
354        static void appendRightAlignedNumber(
355                        StringBuilder theStringBuilder, String thePrefix, int theNumberOfDigits, long theValueToAppend) {
356                theStringBuilder.append(thePrefix);
357                if (theNumberOfDigits > 1) {
358                        int pad = (theNumberOfDigits - 1);
359                        for (long xa = theValueToAppend; xa > 9 && pad > 0; xa /= 10) {
360                                pad--;
361                        }
362                        for (int xa = 0; xa < pad; xa++) {
363                                theStringBuilder.append('0');
364                        }
365                }
366                theStringBuilder.append(theValueToAppend);
367        }
368
369        /**
370         * Formats a number of milliseconds for display (e.g.
371         * in a log file), tailoring the output to how big
372         * the value actually is.
373         * <p>
374         * Example outputs:
375         * </p>
376         * <ul>
377         * <li>133ms</li>
378         * <li>00:00:10.223</li>
379         * <li>1.7 days</li>
380         * <li>64 days</li>
381         * </ul>
382         */
383        public static String formatMillis(long theMillis) {
384                return formatMillis((double) theMillis);
385        }
386
387        /**
388         * Formats a number of milliseconds for display (e.g.
389         * in a log file), tailoring the output to how big
390         * the value actually is.
391         * <p>
392         * Example outputs:
393         * </p>
394         * <ul>
395         * <li>133ms</li>
396         * <li>00:00:10.223</li>
397         * <li>1.7 days</li>
398         * <li>64 days</li>
399         * </ul>
400         */
401        public static String formatMillis(double theMillis) {
402                StringBuilder buf = new StringBuilder(20);
403                if (theMillis > 0.0 && theMillis < 1.0) {
404                        buf.append(getSubMillisecondMillisFormat().format(theMillis));
405                        buf.append("ms");
406                } else if (theMillis < (10 * DateUtils.MILLIS_PER_SECOND)) {
407                        buf.append((int) theMillis);
408                        buf.append("ms");
409                } else if (theMillis >= DateUtils.MILLIS_PER_DAY) {
410                        double days = theMillis / DateUtils.MILLIS_PER_DAY;
411                        if (days >= 10) {
412                                buf.append(getTenDayFormat().format(days));
413                                buf.append(" days");
414                        } else if (days != 1.0f) {
415                                buf.append(getDayFormat().format(days));
416                                buf.append(" days");
417                        } else {
418                                buf.append(getDayFormat().format(days));
419                                buf.append(" day");
420                        }
421                } else {
422                        long millisAsLong = (long) theMillis;
423                        appendRightAlignedNumber(
424                                        buf, "", 2, ((millisAsLong % DateUtils.MILLIS_PER_DAY) / DateUtils.MILLIS_PER_HOUR));
425                        appendRightAlignedNumber(
426                                        buf, ":", 2, ((millisAsLong % DateUtils.MILLIS_PER_HOUR) / DateUtils.MILLIS_PER_MINUTE));
427                        appendRightAlignedNumber(
428                                        buf, ":", 2, ((millisAsLong % DateUtils.MILLIS_PER_MINUTE) / DateUtils.MILLIS_PER_SECOND));
429                        if (theMillis <= DateUtils.MILLIS_PER_MINUTE) {
430                                appendRightAlignedNumber(buf, ".", 3, (millisAsLong % DateUtils.MILLIS_PER_SECOND));
431                        }
432                }
433                return buf.toString();
434        }
435
436        private static long now() {
437                if (ourNowForUnitTest != null) {
438                        return ourNowForUnitTest;
439                }
440                return System.currentTimeMillis();
441        }
442
443        @VisibleForTesting
444        public static void setNowForUnitTest(Long theNowForUnitTest) {
445                ourNowForUnitTest = theNowForUnitTest;
446        }
447
448        private static class TaskTiming {
449                private long myStart;
450                private long myEnd;
451                private String myTaskName;
452
453                public long getEnd() {
454                        if (myEnd == 0) {
455                                return now();
456                        }
457                        return myEnd;
458                }
459
460                public TaskTiming setEnd(long theEnd) {
461                        myEnd = theEnd;
462                        return this;
463                }
464
465                public long getMillis() {
466                        return getEnd() - getStart();
467                }
468
469                public long getStart() {
470                        return myStart;
471                }
472
473                public TaskTiming setStart(long theStart) {
474                        myStart = theStart;
475                        return this;
476                }
477
478                public String getTaskName() {
479                        return myTaskName;
480                }
481
482                public TaskTiming setTaskName(String theTaskName) {
483                        myTaskName = theTaskName;
484                        return this;
485                }
486        }
487}