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