View Javadoc
1   package ca.uhn.fhir.util;
2   
3   import com.google.common.annotations.VisibleForTesting;
4   import org.apache.commons.lang3.time.DateUtils;
5   
6   import java.text.DecimalFormat;
7   import java.text.NumberFormat;
8   import java.util.Date;
9   import java.util.LinkedList;
10  import java.util.List;
11  import java.util.concurrent.TimeUnit;
12  
13  import static org.apache.commons.lang3.StringUtils.isNotBlank;
14  
15  /*
16   * #%L
17   * HAPI FHIR - Core Library
18   * %%
19   * Copyright (C) 2014 - 2018 University Health Network
20   * %%
21   * Licensed under the Apache License, Version 2.0 (the "License");
22   * you may not use this file except in compliance with the License.
23   * You may obtain a copy of the License at
24   * 
25   * http://www.apache.org/licenses/LICENSE-2.0
26   * 
27   * Unless required by applicable law or agreed to in writing, software
28   * distributed under the License is distributed on an "AS IS" BASIS,
29   * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
30   * See the License for the specific language governing permissions and
31   * limitations under the License.
32   * #L%
33   */
34  
35  /**
36   * A multipurpose stopwatch which can be used to time tasks and produce
37   * human readable output about task duration, throughput, estimated task completion,
38   * etc.
39   * <p>
40   * <p>
41   * <b>Thread Safety Note: </b> StopWatch is not intended to be thread safe.
42   * </p>
43   *
44   * @since HAPI FHIR 3.3.0
45   */
46  public class StopWatch {
47  
48  	private static final NumberFormat DAY_FORMAT = new DecimalFormat("0.0");
49  	private static final NumberFormat TEN_DAY_FORMAT = new DecimalFormat("0");
50  	private static Long ourNowForUnitTest;
51  	private long myStarted = now();
52  	private TaskTiming myCurrentTask;
53  	private LinkedList<TaskTiming> myTasks;
54  
55  	/**
56  	 * Constructor
57  	 */
58  	public StopWatch() {
59  		super();
60  	}
61  
62  	/**
63  	 * Constructor
64  	 *
65  	 * @param theStart The time to record as the start for this timer
66  	 */
67  	public StopWatch(Date theStart) {
68  		myStarted = theStart.getTime();
69  	}
70  
71  	private void addNewlineIfContentExists(StringBuilder theB) {
72  		if (theB.length() > 0) {
73  			theB.append("\n");
74  		}
75  	}
76  
77  	/**
78  	 * Finish the counter on the current task (which was started by calling
79  	 * {@link #startTask(String)}. This method has no effect if no task
80  	 * is currently started so it's ok to call it more than once.
81  	 */
82  	public void endCurrentTask() {
83  		ensureTasksListExists();
84  		if (myCurrentTask != null) {
85  			myCurrentTask.setEnd(now());
86  		}
87  		myCurrentTask = null;
88  	}
89  
90  	private void ensureTasksListExists() {
91  		if (myTasks == null) {
92  			myTasks = new LinkedList<>();
93  		}
94  	}
95  
96  	/**
97  	 * Returns a string providing the durations of all tasks collected by {@link #startTask(String)}
98  	 */
99  	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 }