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 - 2021 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 new DecimalFormat("0.0").format(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                long millisRemaining = (long) (((theTotal / theCompleteToDate) * millis) - (millis));
195                return formatMillis(millisRemaining);
196        }
197
198        public long getMillis(Date theNow) {
199                return theNow.getTime() - myStarted;
200        }
201
202        public long getMillis() {
203                long now = now();
204                return now - myStarted;
205        }
206
207        public long getMillisAndRestart() {
208                long now = now();
209                long retVal = now - myStarted;
210                myStarted = now;
211                return retVal;
212        }
213
214        /**
215         * @param theNumOperations Ok for this to be 0, it will be treated as 1
216         */
217        public long getMillisPerOperation(long theNumOperations) {
218                return (long) (((double) getMillis()) / Math.max(1.0, theNumOperations));
219        }
220
221        public Date getStartedDate() {
222                return new Date(myStarted);
223        }
224
225        /**
226         * Determine the current throughput per unit of time (specified in theUnit)
227         * assuming that theNumOperations operations have happened.
228         * <p>
229         * For example, if this stopwatch has 2 seconds elapsed, and this method is
230         * called for theNumOperations=30 and TimeUnit=SECONDS,
231         * this method will return 15
232         * </p>
233         *
234         * @see #formatThroughput(long, TimeUnit)
235         */
236        public double getThroughput(long theNumOperations, TimeUnit theUnit) {
237                if (theNumOperations <= 0) {
238                        return 0.0f;
239                }
240
241                long millisElapsed = Math.max(1, getMillis());
242                long periodMillis = theUnit.toMillis(1);
243
244                double denominator = ((double) millisElapsed) / ((double) periodMillis);
245
246                double throughput = (double) theNumOperations / denominator;
247                if (throughput > theNumOperations) {
248                        throughput = theNumOperations;
249                }
250
251                return throughput;
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        private static class TaskTiming {
288                private long myStart;
289                private long myEnd;
290                private String myTaskName;
291
292                public long getEnd() {
293                        if (myEnd == 0) {
294                                return now();
295                        }
296                        return myEnd;
297                }
298
299                public TaskTiming setEnd(long theEnd) {
300                        myEnd = theEnd;
301                        return this;
302                }
303
304                public long getMillis() {
305                        return getEnd() - getStart();
306                }
307
308                public long getStart() {
309                        return myStart;
310                }
311
312                public TaskTiming setStart(long theStart) {
313                        myStart = theStart;
314                        return this;
315                }
316
317                public String getTaskName() {
318                        return myTaskName;
319                }
320
321                public TaskTiming setTaskName(String theTaskName) {
322                        myTaskName = theTaskName;
323                        return this;
324                }
325        }
326
327        private static NumberFormat getDayFormat() {
328                return new DecimalFormat("0.0");
329        }
330
331        private static NumberFormat getTenDayFormat() {
332                return new DecimalFormat("0");
333        }
334
335        private static NumberFormat getSubMillisecondMillisFormat() {
336                return new DecimalFormat("0.000");
337        }
338
339        /**
340         * Append a right-aligned and zero-padded numeric value to a `StringBuilder`.
341         */
342        static void appendRightAlignedNumber(StringBuilder theStringBuilder, String thePrefix, int theNumberOfDigits, long theValueToAppend) {
343                theStringBuilder.append(thePrefix);
344                if (theNumberOfDigits > 1) {
345                        int pad = (theNumberOfDigits - 1);
346                        for (long xa = theValueToAppend; xa > 9 && pad > 0; xa /= 10) {
347                                pad--;
348                        }
349                        for (int xa = 0; xa < pad; xa++) {
350                                theStringBuilder.append('0');
351                        }
352                }
353                theStringBuilder.append(theValueToAppend);
354        }
355
356        /**
357         * Formats a number of milliseconds for display (e.g.
358         * in a log file), tailoring the output to how big
359         * the value actually is.
360         * <p>
361         * Example outputs:
362         * </p>
363         * <ul>
364         * <li>133ms</li>
365         * <li>00:00:10.223</li>
366         * <li>1.7 days</li>
367         * <li>64 days</li>
368         * </ul>
369         */
370        public static String formatMillis(long theMillis) {
371                return formatMillis((double) theMillis);
372        }
373
374        /**
375         * Formats a number of milliseconds for display (e.g.
376         * in a log file), tailoring the output to how big
377         * the value actually is.
378         * <p>
379         * Example outputs:
380         * </p>
381         * <ul>
382         * <li>133ms</li>
383         * <li>00:00:10.223</li>
384         * <li>1.7 days</li>
385         * <li>64 days</li>
386         * </ul>
387         */
388        public static String formatMillis(double theMillis) {
389                StringBuilder buf = new StringBuilder(20);
390                if (theMillis > 0.0 && theMillis < 1.0) {
391                        buf.append(getSubMillisecondMillisFormat().format(theMillis));
392                        buf.append("ms");
393                } else if (theMillis < (10 * DateUtils.MILLIS_PER_SECOND)) {
394                        buf.append((int) theMillis);
395                        buf.append("ms");
396                } else if (theMillis >= DateUtils.MILLIS_PER_DAY) {
397                        double days = theMillis / DateUtils.MILLIS_PER_DAY;
398                        if (days >= 10) {
399                                buf.append(getTenDayFormat().format(days));
400                                buf.append(" days");
401                        } else if (days != 1.0f) {
402                                buf.append(getDayFormat().format(days));
403                                buf.append(" days");
404                        } else {
405                                buf.append(getDayFormat().format(days));
406                                buf.append(" day");
407                        }
408                } else {
409                        long millisAsLong = (long) theMillis;
410                        appendRightAlignedNumber(buf, "", 2, ((millisAsLong % DateUtils.MILLIS_PER_DAY) / DateUtils.MILLIS_PER_HOUR));
411                        appendRightAlignedNumber(buf, ":", 2, ((millisAsLong % DateUtils.MILLIS_PER_HOUR) / DateUtils.MILLIS_PER_MINUTE));
412                        appendRightAlignedNumber(buf, ":", 2, ((millisAsLong % DateUtils.MILLIS_PER_MINUTE) / DateUtils.MILLIS_PER_SECOND));
413                        if (theMillis <= DateUtils.MILLIS_PER_MINUTE) {
414                                appendRightAlignedNumber(buf, ".", 3, (millisAsLong % DateUtils.MILLIS_PER_SECOND));
415                        }
416                }
417                return buf.toString();
418        }
419
420        private static long now() {
421                if (ourNowForUnitTest != null) {
422                        return ourNowForUnitTest;
423                }
424                return System.currentTimeMillis();
425        }
426
427        @VisibleForTesting
428        static void setNowForUnitTestForUnitTest(Long theNowForUnitTest) {
429                ourNowForUnitTest = theNowForUnitTest;
430        }
431
432}