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 - 2022 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        private static Long ourNowForUnitTest;
047        private long myStarted = now();
048        private TaskTiming myCurrentTask;
049        private LinkedList<TaskTiming> myTasks;
050
051        /**
052         * Constructor
053         */
054        public StopWatch() {
055                super();
056        }
057
058        /**
059         * Constructor
060         *
061         * @param theStart The time to record as the start for this timer
062         */
063        public StopWatch(Date theStart) {
064                myStarted = theStart.getTime();
065        }
066
067        /**
068         * Constructor
069         *
070         * @param theStart The time that the stopwatch was started
071         */
072        public StopWatch(long theStart) {
073                myStarted = theStart;
074        }
075
076        private void addNewlineIfContentExists(StringBuilder theB) {
077                if (theB.length() > 0) {
078                        theB.append("\n");
079                }
080        }
081
082        /**
083         * Finish the counter on the current task (which was started by calling
084         * {@link #startTask(String)}. This method has no effect if no task
085         * is currently started so it's ok to call it more than once.
086         */
087        public void endCurrentTask() {
088                ensureTasksListExists();
089                if (myCurrentTask != null) {
090                        myCurrentTask.setEnd(now());
091                }
092                myCurrentTask = null;
093        }
094
095        private void ensureTasksListExists() {
096                if (myTasks == null) {
097                        myTasks = new LinkedList<>();
098                }
099        }
100
101        /**
102         * Returns a nice human-readable display of the time taken per
103         * operation. Note that this may not actually output the number
104         * of milliseconds if the time taken per operation was very long (over
105         * 10 seconds)
106         *
107         * @see #formatMillis(long)
108         */
109        public String formatMillisPerOperation(long theNumOperations) {
110                double millisPerOperation = (((double) getMillis()) / Math.max(1.0, theNumOperations));
111                return formatMillis(millisPerOperation);
112        }
113
114        /**
115         * Returns a string providing the durations of all tasks collected by {@link #startTask(String)}
116         */
117        public String formatTaskDurations() {
118
119                ensureTasksListExists();
120                StringBuilder b = new StringBuilder();
121
122                if (myTasks.size() > 0) {
123                        long delta = myTasks.getFirst().getStart() - myStarted;
124                        if (delta > 10) {
125                                addNewlineIfContentExists(b);
126                                b.append("Before first task");
127                                b.append(": ");
128                                b.append(formatMillis(delta));
129                        }
130                } else {
131                        b.append("No tasks");
132                }
133
134                TaskTiming last = null;
135                for (TaskTiming nextTask : myTasks) {
136
137                        if (last != null) {
138                                long delta = nextTask.getStart() - last.getEnd();
139                                if (delta > 10) {
140                                        addNewlineIfContentExists(b);
141                                        b.append("Between");
142                                        b.append(": ");
143                                        b.append(formatMillis(delta));
144                                }
145                        }
146
147                        addNewlineIfContentExists(b);
148                        b.append(nextTask.getTaskName());
149                        b.append(": ");
150                        long delta = nextTask.getMillis();
151                        b.append(formatMillis(delta));
152
153                        last = nextTask;
154                }
155
156                if (myTasks.size() > 0) {
157                        long delta = now() - myTasks.getLast().getEnd();
158                        if (delta > 10) {
159                                addNewlineIfContentExists(b);
160                                b.append("After last task");
161                                b.append(": ");
162                                b.append(formatMillis(delta));
163                        }
164                }
165
166                return b.toString();
167        }
168
169        /**
170         * Determine the current throughput per unit of time (specified in theUnit)
171         * assuming that theNumOperations operations have happened.
172         * <p>
173         * For example, if this stopwatch has 2 seconds elapsed, and this method is
174         * called for theNumOperations=30 and TimeUnit=SECONDS,
175         * this method will return 15
176         * </p>
177         *
178         * @see #getThroughput(long, TimeUnit)
179         */
180        public String formatThroughput(long theNumOperations, TimeUnit theUnit) {
181                double throughput = getThroughput(theNumOperations, theUnit);
182                return formatThroughput(throughput);
183        }
184
185        /**
186         * Given an amount of something completed so far, and a total amount, calculates how long it will take for something to complete
187         *
188         * @param theCompleteToDate The amount so far
189         * @param theTotal          The total (must be higher than theCompleteToDate
190         * @return A formatted amount of time
191         */
192        public String getEstimatedTimeRemaining(double theCompleteToDate, double theTotal) {
193                double millis = getMillis();
194                return formatEstimatedTimeRemaining(theCompleteToDate, theTotal, millis);
195        }
196
197        /**
198         * Given an amount of something completed so far, and a total amount, calculates how long it will take for something to complete
199         *
200         * @param theCompleteToDate The amount so far
201         * @param theTotal          The total (must be higher than theCompleteToDate
202         * @return A formatted amount of time
203         */
204        public static String formatEstimatedTimeRemaining(double theCompleteToDate, double theTotal, double millis) {
205                long millisRemaining = (long) (((theTotal / theCompleteToDate) * millis) - millis);
206                return formatMillis(millisRemaining);
207        }
208
209        public long getMillis(Date theNow) {
210                return theNow.getTime() - myStarted;
211        }
212
213        public long getMillis() {
214                long now = now();
215                return now - myStarted;
216        }
217
218        public long getMillisAndRestart() {
219                long now = now();
220                long retVal = now - myStarted;
221                myStarted = now;
222                return retVal;
223        }
224
225        /**
226         * @param theNumOperations Ok for this to be 0, it will be treated as 1
227         */
228        public long getMillisPerOperation(long theNumOperations) {
229                return (long) (((double) getMillis()) / Math.max(1.0, theNumOperations));
230        }
231
232        public Date getStartedDate() {
233                return new Date(myStarted);
234        }
235
236        /**
237         * Determine the current throughput per unit of time (specified in theUnit)
238         * assuming that theNumOperations operations have happened.
239         * <p>
240         * For example, if this stopwatch has 2 seconds elapsed, and this method is
241         * called for theNumOperations=30 and TimeUnit=SECONDS,
242         * this method will return 15
243         * </p>
244         *
245         * @see #formatThroughput(long, TimeUnit)
246         */
247        public double getThroughput(long theNumOperations, TimeUnit theUnit) {
248                long millis = getMillis();
249                return getThroughput(theNumOperations, millis, theUnit);
250        }
251
252        public void restart() {
253                myStarted = now();
254        }
255
256        /**
257         * Starts a counter for a sub-task
258         * <p>
259         * <b>Thread Safety Note: </b> This method is not threadsafe! Do not use subtasks in a
260         * multithreaded environment.
261         * </p>
262         *
263         * @param theTaskName Note that if theTaskName is blank or empty, no task is started
264         */
265        public void startTask(String theTaskName) {
266                endCurrentTask();
267                Validate.notBlank(theTaskName, "Task name must not be blank");
268                myCurrentTask = new TaskTiming()
269                        .setTaskName(theTaskName)
270                        .setStart(now());
271                myTasks.add(myCurrentTask);
272        }
273
274        /**
275         * Formats value in an appropriate format. See {@link #formatMillis(long)}}
276         * for a description of the format
277         *
278         * @see #formatMillis(long)
279         */
280        @Override
281        public String toString() {
282                return formatMillis(getMillis());
283        }
284
285        /**
286         * Format a throughput number (output does not include units)
287         */
288        public static String formatThroughput(double throughput) {
289                return new DecimalFormat("0.0").format(throughput);
290        }
291
292        /**
293         * Calculate throughput
294         *
295         * @param theNumOperations The number of operations completed
296         * @param theMillisElapsed The time elapsed
297         * @param theUnit          The unit for the throughput
298         */
299        public static double getThroughput(long theNumOperations, long theMillisElapsed, TimeUnit theUnit) {
300                if (theNumOperations <= 0) {
301                        return 0.0f;
302                }
303                long millisElapsed = Math.max(1, theMillisElapsed);
304                long periodMillis = theUnit.toMillis(1);
305
306                double denominator = ((double) millisElapsed) / ((double) periodMillis);
307
308                double throughput = (double) theNumOperations / denominator;
309                if (throughput > theNumOperations) {
310                        throughput = theNumOperations;
311                }
312
313                return throughput;
314        }
315
316        private static NumberFormat getDayFormat() {
317                return new DecimalFormat("0.0");
318        }
319
320        private static NumberFormat getTenDayFormat() {
321                return new DecimalFormat("0");
322        }
323
324        private static NumberFormat getSubMillisecondMillisFormat() {
325                return new DecimalFormat("0.000");
326        }
327
328        /**
329         * Append a right-aligned and zero-padded numeric value to a `StringBuilder`.
330         */
331        static void appendRightAlignedNumber(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(buf, "", 2, ((millisAsLong % DateUtils.MILLIS_PER_DAY) / DateUtils.MILLIS_PER_HOUR));
400                        appendRightAlignedNumber(buf, ":", 2, ((millisAsLong % DateUtils.MILLIS_PER_HOUR) / DateUtils.MILLIS_PER_MINUTE));
401                        appendRightAlignedNumber(buf, ":", 2, ((millisAsLong % DateUtils.MILLIS_PER_MINUTE) / DateUtils.MILLIS_PER_SECOND));
402                        if (theMillis <= DateUtils.MILLIS_PER_MINUTE) {
403                                appendRightAlignedNumber(buf, ".", 3, (millisAsLong % DateUtils.MILLIS_PER_SECOND));
404                        }
405                }
406                return buf.toString();
407        }
408
409        private static long now() {
410                if (ourNowForUnitTest != null) {
411                        return ourNowForUnitTest;
412                }
413                return System.currentTimeMillis();
414        }
415
416        @VisibleForTesting
417        static void setNowForUnitTestForUnitTest(Long theNowForUnitTest) {
418                ourNowForUnitTest = theNowForUnitTest;
419        }
420
421        private static class TaskTiming {
422                private long myStart;
423                private long myEnd;
424                private String myTaskName;
425
426                public long getEnd() {
427                        if (myEnd == 0) {
428                                return now();
429                        }
430                        return myEnd;
431                }
432
433                public TaskTiming setEnd(long theEnd) {
434                        myEnd = theEnd;
435                        return this;
436                }
437
438                public long getMillis() {
439                        return getEnd() - getStart();
440                }
441
442                public long getStart() {
443                        return myStart;
444                }
445
446                public TaskTiming setStart(long theStart) {
447                        myStart = theStart;
448                        return this;
449                }
450
451                public String getTaskName() {
452                        return myTaskName;
453                }
454
455                public TaskTiming setTaskName(String theTaskName) {
456                        myTaskName = theTaskName;
457                        return this;
458                }
459        }
460
461}