1 /* Tracking cpu/system/elapsed time used by a process.
2  *
3  * Credits:
4  *   - Thanks to Warren Gish for assistance.
5  *   - Includes portable high-resolution timer code
6  *     (C) 2012 David Robert Nadeau, http://NadeauSoftware.com/
7  *     Creative Commons Attribution 3.0 Unported License
8  *     http://creativecommons.org/licenses/by/3.0/deed.en_US
9  */
10 #include "esl_config.h"
11 
12 #include "easel.h"
13 #include "esl_stopwatch.h"
14 
15 static double stopwatch_getRealTime(void);
16 
17 /*****************************************************************
18  * ESL_STOPWATCH object maintenance
19  *****************************************************************/
20 
21 /* Function:  esl_stopwatch_Create()
22  *
23  * Purpose:   Creates a new stopwatch.
24  *
25  * Returns:   ptr to a new <ESL_STOPWATCH> object; caller is
26  *            responsible for free'ing it with
27  *            <esl_stopwatch_Destroy()>.
28  *
29  * Throws:    NULL on allocation failure.
30  */
31 ESL_STOPWATCH *
esl_stopwatch_Create(void)32 esl_stopwatch_Create(void)
33 {
34   ESL_STOPWATCH *w = NULL;
35   int status;
36 
37   ESL_ALLOC(w, sizeof(ESL_STOPWATCH));
38   w->elapsed = 0.;
39   w->user    = 0.;
40   w->sys     = 0.;
41   return w;
42 
43  ERROR:
44   esl_stopwatch_Destroy(w);
45   return NULL;
46 }
47 
48 /* Function:  esl_stopwatch_Destroy()
49  *
50  * Purpose:   Frees an <ESL_STOPWATCH>.
51  */
52 void
esl_stopwatch_Destroy(ESL_STOPWATCH * w)53 esl_stopwatch_Destroy(ESL_STOPWATCH *w)
54 {
55   if (w)
56     free(w);
57 }
58 
59 
60 
61 /* Function:  esl_stopwatch_Start()
62  *
63  * Purpose:   Start a stopwatch. This sets the base
64  *            for elapsed, cpu, and system time difference
65  *            calculations by subsequent calls to
66  *            <esl_stopwatch_Stop()>.
67  *
68  * Returns:   <eslOK> on success.
69  */
70 int
esl_stopwatch_Start(ESL_STOPWATCH * w)71 esl_stopwatch_Start(ESL_STOPWATCH *w)
72 {
73 #if defined HAVE_TIMES && defined eslSTOPWATCH_HIGHRES /* System-dependent highest resolution */
74   times(&(w->cpu0));
75   w->t0   = stopwatch_getRealTime();
76 #elif  HAVE_TIMES           /*   ... else fall back to POSIX... */
77   w->t0   = times(&(w->cpu0));
78 #else                       /*   ... else fallback to ANSI C */
79   w->t0   = time(NULL);
80   w->cpu0 = clock();
81 #endif
82 
83   w->elapsed = 0.;
84   w->user    = 0.;
85   w->sys     = 0.;
86   return eslOK;
87 }
88 
89 /* Function:  esl_stopwatch_Stop()
90  *
91  * Purpose:   Stop a stopwatch. Record and store elapsed,
92  *            cpu, and system time difference relative to the
93  *            last call to <esl_stopwatch_Start()>.
94  *
95  * Returns:   <eslOK> on success.
96  */
97 int
esl_stopwatch_Stop(ESL_STOPWATCH * w)98 esl_stopwatch_Stop(ESL_STOPWATCH *w)
99 {
100 #if defined eslSTOPWATCH_HIGHRES && defined HAVE_TIMES
101   double     t1;
102   struct tms cpu1;
103   double     clk_tck;
104 #elif defined HAVE_TIMES
105   clock_t    t1;
106   struct tms cpu1;
107   double     clk_tck;
108 #else
109   time_t     t1;
110   clock_t    cpu1;
111 #endif
112 
113 
114 #if defined eslSTOPWATCH_HIGHRES && defined HAVE_TIMES
115   t1         = stopwatch_getRealTime();
116   w->elapsed = t1 - w->t0;
117   clk_tck    =  (double) sysconf(_SC_CLK_TCK);
118   times(&cpu1);
119   w->user    = (double) (cpu1.tms_utime + cpu1.tms_cutime -
120 			 w->cpu0.tms_utime - w->cpu0.tms_cutime) / clk_tck;
121   w->sys     = (double) (cpu1.tms_stime + cpu1.tms_cstime -
122 			 w->cpu0.tms_stime - w->cpu0.tms_cstime) / clk_tck;
123 #elif defined HAVE_TIMES /* POSIX */
124   t1         = times(&cpu1);
125   clk_tck    = (double) sysconf(_SC_CLK_TCK);
126   w->elapsed = (double) (t1 - w->t0) / clk_tck;
127   w->user    = (double) (cpu1.tms_utime + cpu1.tms_cutime -
128 			 w->cpu0.tms_utime - w->cpu0.tms_cutime) / clk_tck;
129   w->sys     = (double) (cpu1.tms_stime + cpu1.tms_cstime -
130 			 w->cpu0.tms_stime - w->cpu0.tms_cstime) / clk_tck;
131 #else /* fallback to ANSI C */
132   t1         = time(NULL);
133   cpu1       = clock();
134   w->elapsed = difftime(t1, w->t0);
135   w->user    = (double) (cpu1- w->cpu0) / (double) CLOCKS_PER_SEC;
136   w->sys     = 0.;		/* no way to portably get system time in ANSI C */
137 #endif
138 
139   return eslOK;
140 }
141 
142 /* format_time_string()
143  * Date:     SRE, Fri Nov 26 15:06:28 1999 [St. Louis]
144  *
145  * Purpose:  Given a number of seconds, format into
146  *           hh:mm:ss.xx in a provided buffer.
147  *
148  * Args:     buf     - allocated space (128 is plenty!)
149  *           sec     - number of seconds
150  *           do_frac - TRUE (1) to include hundredths of a sec
151  */
152 static void
format_time_string(char * buf,double sec,int do_frac)153 format_time_string(char *buf, double sec, int do_frac)
154 {
155   int h, m, s, hs;
156 
157   h  = (int) (sec / 3600.);
158   m  = (int) (sec / 60.) - h * 60;
159   s  = (int) (sec) - h * 3600 - m * 60;
160   if (do_frac) {
161     hs = (int) (sec * 100.) - h * 360000 - m * 6000 - s * 100;
162     sprintf(buf, "%02d:%02d:%02d.%02d", h,m,s,hs);
163   } else {
164     sprintf(buf, "%02d:%02d:%02d", h,m,s);
165   }
166 }
167 
168 /* Function:  esl_stopwatch_Display()
169  *
170  * Purpose:   Output a usage summary line from a stopped
171  *            stopwatch, showing elapsed, cpu, and system time
172  *            between the last calls to
173  *            <esl_stopwatch_Start()> and <esl_stopwatch_Stop()>.
174  *
175  *            The string <prefix> will be prepended to the output
176  *            line. Use <""> to prepend nothing. If <prefix> is NULL,
177  *            a default <"CPU Time: "> prefix is used.
178  *
179  *            For <prefix> = <"CPU Time: "> an example output line is:\\
180  *            <CPU Time: 142.55u 7.17s 00:02:29.72 Elapsed: 00:02:35>
181  *
182  * Args:      fp      - output stream
183  *            w       - stopped stopwatch
184  *            prefix  - output line prefix ("" for nothing)
185  *
186  * Returns:   <eslOK> on success.
187  *
188  * Throws:    <eslEWRITE> on any system write error, such as filled disk.
189  */
190 int
esl_stopwatch_Display(FILE * fp,ESL_STOPWATCH * w,char * prefix)191 esl_stopwatch_Display(FILE *fp, ESL_STOPWATCH *w, char *prefix)
192 {
193   char buf[128];	/* (safely holds up to 10^14 years; I'll be dead by then) */
194 
195   if (prefix == NULL) { if (fputs("CPU Time: ", fp) < 0) ESL_EXCEPTION_SYS(eslEWRITE, "stopwatch display write failed"); }
196   else                { if (fputs(prefix, fp)       < 0) ESL_EXCEPTION_SYS(eslEWRITE, "stopwatch display write failed"); }
197 
198   format_time_string(buf, w->user+w->sys, TRUE);
199 #ifdef HAVE_TIMES
200   if (fprintf(fp, "%.2fu %.2fs %s ", w->user, w->sys, buf) < 0) ESL_EXCEPTION_SYS(eslEWRITE, "stopwatch display write failed");
201 #else
202   if (fprintf(fp, "%.2fu %s ", w->user, buf)               < 0) ESL_EXCEPTION_SYS(eslEWRITE, "stopwatch display write failed");
203 #endif
204   format_time_string(buf, w->elapsed, TRUE);
205   if (fprintf(fp, "Elapsed: %s\n", buf)                    < 0) ESL_EXCEPTION_SYS(eslEWRITE, "stopwatch display write failed");
206   return eslOK;
207 }
208 
209 
210 
211 /* Function:  esl_stopwatch_GetElapsed()
212  * Synopsis:  Return the elapsed time in seconds
213  * Incept:    SRE, Fri Jan  8 10:10:37 2016
214  *
215  * Purpose:   After watch <w> is Stop()'ed, calling
216  *            <esl_stopwatch_GetElapsed(w)> returns the elapsed time
217  *            in seconds.
218  *
219  *            The resolution is system-dependent.
220  */
221 double
esl_stopwatch_GetElapsed(ESL_STOPWATCH * w)222 esl_stopwatch_GetElapsed(ESL_STOPWATCH *w)
223 {
224   return w->elapsed;
225 }
226 
227 
228 /* Function:  esl_stopwatch_Include()
229  *
230  * Purpose:   Merge the cpu and system times from a slave into
231  *            a master stopwatch. Both watches must be
232  *            stopped, and should not be stopped again unless
233  *            You Know What You're Doing.
234  *
235  *            Elapsed time is not merged. Master is assumed
236  *            to be keeping track of the wall clock (real) time,
237  *            and the slave/worker watch is ignored.
238  *
239  *            Useful in at least two cases. One is in
240  *            PVM, where we merge in the stopwatch(es) from separate
241  *            process(es) in a cluster. A second is in
242  *            threads, for broken pthreads/times() implementations
243  *            that lose track of cpu times used by spawned
244  *            threads.
245  *
246  * Args:      master  - stopwatch that's aggregating times
247  *            w       - watch to add to the master.
248  *
249  * Returns:   <eslOK> on success.
250  */
251 int
esl_stopwatch_Include(ESL_STOPWATCH * master,ESL_STOPWATCH * w)252 esl_stopwatch_Include(ESL_STOPWATCH *master, ESL_STOPWATCH *w)
253 {
254   master->user    += w->user;
255   master->sys     += w->sys;
256   return eslOK;
257 }
258 
259 
260 /*****************************************************************
261  * Portable high resolution timing
262  *****************************************************************/
263 #ifdef eslSTOPWATCH_HIGHRES
264 
265 /* The following code is
266  * (C) 2012 David Robert Nadeau, http://NadeauSoftware.com
267  * Creative Commons Attribution 3.0 Unported License
268  * http://creativecommons.org/licenses/by/3.0/deed.en_US
269  *
270  * Reference: http://nadeausoftware.com/articles/2012/04/c_c_tip_how_measure_elapsed_real_time_benchmarking
271  *
272  * On resolution:
273  *   I believe that on Mac OS/X, the high performance timer has a resolution in units
274  *   of nanoseconds (at least on some platforms, including my laptop). However, calling
275  *   the esl_stopwatch_* functions themselves have overhead. The example driver is
276  *   a reasonable test of the minimal resolution, including call overhead; that gives
277  *   me about 0.1 microseconds (12 Jan 2016).
278  */
279 #if defined(_WIN32)
280 #include <Windows.h>
281 
282 #elif defined(__unix__) || defined(__unix) || defined(unix) || (defined(__APPLE__) && defined(__MACH__))
283 #include <unistd.h>	/* POSIX flags */
284 #include <time.h>	/* clock_gettime(), time() */
285 #include <sys/time.h>	/* gethrtime(), gettimeofday() */
286 
287 #if defined(__MACH__) && defined(__APPLE__)
288 #include <mach/mach.h>
289 #include <mach/mach_time.h>
290 #endif
291 
292 #else
293 #error "Unable to define getRealTime( ) for an unknown OS."
294 #endif
295 
296 /**
297  * Returns the real time, in seconds, or -1.0 if an error occurred.
298  *
299  * Time is measured since an arbitrary and OS-dependent start time.
300  * The returned real time is only useful for computing an elapsed time
301  * between two calls to this function.
302  */
303 static double
stopwatch_getRealTime(void)304 stopwatch_getRealTime(void)
305 {
306 #if defined(_WIN32)
307 	FILETIME tm;
308 	ULONGLONG t;
309 #if defined(NTDDI_WIN8) && NTDDI_VERSION >= NTDDI_WIN8
310 	/* Windows 8, Windows Server 2012 and later. ---------------- */
311 	GetSystemTimePreciseAsFileTime( &tm );
312 #else
313 	/* Windows 2000 and later. ---------------------------------- */
314 	GetSystemTimeAsFileTime( &tm );
315 #endif
316 	t = ((ULONGLONG)tm.dwHighDateTime << 32) | (ULONGLONG)tm.dwLowDateTime;
317 	return (double)t / 10000000.0;
318 
319 #elif (defined(__hpux) || defined(hpux)) || ((defined(__sun__) || defined(__sun) || defined(sun)) && (defined(__SVR4) || defined(__svr4__)))
320 	/* HP-UX, Solaris. ------------------------------------------ */
321 	return (double)gethrtime( ) / 1000000000.0;
322 
323 #elif defined(__MACH__) && defined(__APPLE__)
324 	/* OSX. ----------------------------------------------------- */
325 	static double timeConvert = 0.0;
326 	if ( timeConvert == 0.0 )
327 	{
328 		mach_timebase_info_data_t timeBase;
329 		(void)mach_timebase_info( &timeBase );
330 		timeConvert = (double)timeBase.numer /
331 			(double)timeBase.denom /
332 			1000000000.0;
333 	}
334 	return (double)mach_absolute_time( ) * timeConvert;
335 
336 #elif defined(_POSIX_VERSION)
337 	/* POSIX. --------------------------------------------------- */
338 #if defined(_POSIX_TIMERS) && (_POSIX_TIMERS > 0)
339 	{
340 		struct timespec ts;
341 #if defined(CLOCK_MONOTONIC_PRECISE)
342 		/* BSD. --------------------------------------------- */
343 		const clockid_t id = CLOCK_MONOTONIC_PRECISE;
344 #elif defined(CLOCK_MONOTONIC_RAW)
345 		/* Linux. ------------------------------------------- */
346 		const clockid_t id = CLOCK_MONOTONIC_RAW;
347 #elif defined(CLOCK_HIGHRES)
348 		/* Solaris. ----------------------------------------- */
349 		const clockid_t id = CLOCK_HIGHRES;
350 #elif defined(CLOCK_MONOTONIC)
351 		/* AIX, BSD, Linux, POSIX, Solaris. ----------------- */
352 		const clockid_t id = CLOCK_MONOTONIC;
353 #elif defined(CLOCK_REALTIME)
354 		/* AIX, BSD, HP-UX, Linux, POSIX. ------------------- */
355 		const clockid_t id = CLOCK_REALTIME;
356 #else
357 		const clockid_t id = (clockid_t)-1;	/* Unknown. */
358 #endif /* CLOCK_* */
359 		if ( id != (clockid_t)-1 && clock_gettime( id, &ts ) != -1 )
360 			return (double)ts.tv_sec +
361 				(double)ts.tv_nsec / 1000000000.0;
362 		/* Fall thru. */
363 	}
364 #endif /* _POSIX_TIMERS */
365 
366 	/* AIX, BSD, Cygwin, HP-UX, Linux, OSX, POSIX, Solaris. ----- */
367 	struct timeval tm;
368 	gettimeofday( &tm, NULL );
369 	return (double)tm.tv_sec + (double)tm.tv_usec / 1000000.0;
370 #else
371 	return -1.0;		/* Failed. */
372 #endif
373 }
374 #endif /*eslSTOPWATCH_HIGHRES*/
375 
376 /*****************************************************************
377  * Example of using the stopwatch module
378  *****************************************************************/
379 #ifdef eslSTOPWATCH_EXAMPLE
380 /*::cexcerpt::stopwatch_example::begin::*/
381 /* compile: gcc -g -Wall -I. -o example -DeslSTOPWATCH_EXAMPLE esl_stopwatch.c easel.c -lm
382  * run:     ./example
383  */
384 #include "easel.h"
385 #include "esl_stopwatch.h"
386 
387 int
main(void)388 main(void)
389 {
390   ESL_STOPWATCH *w;
391   double         t = 0.;
392 
393   w = esl_stopwatch_Create();
394 
395   /* This tests the minimum *practical* resolution of the clock,
396    * inclusive of overhead of calling the stopwatch functions.
397    * It gives me ~0.1 usec (12 Jan 2016).
398    */
399   esl_stopwatch_Start(w);
400   while (t == 0.)
401     {
402       esl_stopwatch_Stop(w);
403       t = esl_stopwatch_GetElapsed(w);
404     }
405 
406   printf("Elapsed time clock has practical resolution of around: %g sec\n", t);
407 
408   esl_stopwatch_Display(stdout, w, "CPU Time: ");
409   esl_stopwatch_Destroy(w);
410   return 0;
411 }
412 /*::cexcerpt::stopwatch_example::end::*/
413 #endif /*ESL_STOPWATCH_EXAMPLE*/
414 
415 
416