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