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