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