Commit | Line | Data |
---|---|---|
02bcaa8c | 1 | /* |
f5cc024a | 2 | * Clock functions |
02bcaa8c | 3 | */ |
f5cc024a | 4 | |
02bcaa8c | 5 | #include <unistd.h> |
c223da83 | 6 | #include <math.h> |
02bcaa8c | 7 | #include <sys/time.h> |
03e20d68 | 8 | #include <time.h> |
02bcaa8c JA |
9 | |
10 | #include "fio.h" | |
be4ecfdf | 11 | #include "smalloc.h" |
02bcaa8c JA |
12 | |
13 | #include "hash.h" | |
7d11f871 | 14 | #include "os/os.h" |
02bcaa8c | 15 | |
09a32402 | 16 | #ifdef ARCH_HAVE_CPU_CLOCK |
c223da83 | 17 | static unsigned long cycles_per_usec; |
71339117 | 18 | static unsigned long inv_cycles_per_usec; |
09a32402 | 19 | #endif |
4de98eb0 | 20 | int tsc_reliable = 0; |
5d879392 JA |
21 | |
22 | struct tv_valid { | |
23 | struct timeval last_tv; | |
24 | int last_tv_valid; | |
93f0b09a | 25 | unsigned long last_cycles; |
5d879392 JA |
26 | }; |
27 | static pthread_key_t tv_tls_key; | |
02bcaa8c | 28 | |
16de1bf9 | 29 | enum fio_cs fio_clock_source = FIO_PREFERRED_CLOCK_SOURCE; |
fa80feae | 30 | int fio_clock_source_set = 0; |
01423eae | 31 | enum fio_cs fio_clock_source_inited = CS_INVAL; |
c223da83 | 32 | |
02bcaa8c JA |
33 | #ifdef FIO_DEBUG_TIME |
34 | ||
35 | #define HASH_BITS 8 | |
36 | #define HASH_SIZE (1 << HASH_BITS) | |
37 | ||
01743ee1 | 38 | static struct flist_head hash[HASH_SIZE]; |
02bcaa8c JA |
39 | static int gtod_inited; |
40 | ||
41 | struct gtod_log { | |
01743ee1 | 42 | struct flist_head list; |
02bcaa8c JA |
43 | void *caller; |
44 | unsigned long calls; | |
45 | }; | |
46 | ||
47 | static struct gtod_log *find_hash(void *caller) | |
48 | { | |
49 | unsigned long h = hash_ptr(caller, HASH_BITS); | |
01743ee1 | 50 | struct flist_head *entry; |
02bcaa8c | 51 | |
01743ee1 JA |
52 | flist_for_each(entry, &hash[h]) { |
53 | struct gtod_log *log = flist_entry(entry, struct gtod_log, | |
54 | list); | |
02bcaa8c JA |
55 | |
56 | if (log->caller == caller) | |
57 | return log; | |
58 | } | |
59 | ||
60 | return NULL; | |
61 | } | |
62 | ||
63 | static struct gtod_log *find_log(void *caller) | |
64 | { | |
65 | struct gtod_log *log = find_hash(caller); | |
66 | ||
67 | if (!log) { | |
68 | unsigned long h; | |
69 | ||
70 | log = malloc(sizeof(*log)); | |
01743ee1 | 71 | INIT_FLIST_HEAD(&log->list); |
02bcaa8c JA |
72 | log->caller = caller; |
73 | log->calls = 0; | |
74 | ||
75 | h = hash_ptr(caller, HASH_BITS); | |
01743ee1 | 76 | flist_add_tail(&log->list, &hash[h]); |
02bcaa8c JA |
77 | } |
78 | ||
79 | return log; | |
80 | } | |
81 | ||
82 | static void gtod_log_caller(void *caller) | |
83 | { | |
84 | if (gtod_inited) { | |
85 | struct gtod_log *log = find_log(caller); | |
86 | ||
87 | log->calls++; | |
88 | } | |
89 | } | |
90 | ||
91 | static void fio_exit fio_dump_gtod(void) | |
92 | { | |
93 | unsigned long total_calls = 0; | |
94 | int i; | |
95 | ||
96 | for (i = 0; i < HASH_SIZE; i++) { | |
01743ee1 | 97 | struct flist_head *entry; |
02bcaa8c JA |
98 | struct gtod_log *log; |
99 | ||
01743ee1 JA |
100 | flist_for_each(entry, &hash[i]) { |
101 | log = flist_entry(entry, struct gtod_log, list); | |
02bcaa8c | 102 | |
5ec10eaa JA |
103 | printf("function %p, calls %lu\n", log->caller, |
104 | log->calls); | |
02bcaa8c JA |
105 | total_calls += log->calls; |
106 | } | |
107 | } | |
108 | ||
109 | printf("Total %lu gettimeofday\n", total_calls); | |
110 | } | |
111 | ||
112 | static void fio_init gtod_init(void) | |
113 | { | |
114 | int i; | |
115 | ||
116 | for (i = 0; i < HASH_SIZE; i++) | |
01743ee1 | 117 | INIT_FLIST_HEAD(&hash[i]); |
02bcaa8c JA |
118 | |
119 | gtod_inited = 1; | |
120 | } | |
121 | ||
122 | #endif /* FIO_DEBUG_TIME */ | |
123 | ||
9ff1c070 JA |
124 | static int fill_clock_gettime(struct timespec *ts) |
125 | { | |
126 | #ifdef FIO_HAVE_CLOCK_MONOTONIC | |
127 | return clock_gettime(CLOCK_MONOTONIC, ts); | |
128 | #else | |
129 | return clock_gettime(CLOCK_REALTIME, ts); | |
130 | #endif | |
131 | } | |
132 | ||
1e97cce9 | 133 | #ifdef FIO_DEBUG_TIME |
02bcaa8c | 134 | void fio_gettime(struct timeval *tp, void *caller) |
1e97cce9 JA |
135 | #else |
136 | void fio_gettime(struct timeval *tp, void fio_unused *caller) | |
137 | #endif | |
02bcaa8c | 138 | { |
93f0b09a | 139 | struct tv_valid *tv; |
5d879392 | 140 | |
02bcaa8c JA |
141 | #ifdef FIO_DEBUG_TIME |
142 | if (!caller) | |
143 | caller = __builtin_return_address(0); | |
144 | ||
145 | gtod_log_caller(caller); | |
02bcaa8c | 146 | #endif |
be4ecfdf JA |
147 | if (fio_tv) { |
148 | memcpy(tp, fio_tv, sizeof(*tp)); | |
149 | return; | |
c223da83 JA |
150 | } |
151 | ||
93f0b09a JA |
152 | tv = pthread_getspecific(tv_tls_key); |
153 | ||
c223da83 JA |
154 | switch (fio_clock_source) { |
155 | case CS_GTOD: | |
02bcaa8c | 156 | gettimeofday(tp, NULL); |
c223da83 JA |
157 | break; |
158 | case CS_CGETTIME: { | |
02bcaa8c JA |
159 | struct timespec ts; |
160 | ||
9ff1c070 | 161 | if (fill_clock_gettime(&ts) < 0) { |
c223da83 JA |
162 | log_err("fio: clock_gettime fails\n"); |
163 | assert(0); | |
02bcaa8c JA |
164 | } |
165 | ||
166 | tp->tv_sec = ts.tv_sec; | |
167 | tp->tv_usec = ts.tv_nsec / 1000; | |
c223da83 JA |
168 | break; |
169 | } | |
170 | #ifdef ARCH_HAVE_CPU_CLOCK | |
171 | case CS_CPUCLOCK: { | |
172 | unsigned long long usecs, t; | |
173 | ||
174 | t = get_cpu_clock(); | |
93f0b09a | 175 | if (tv && t < tv->last_cycles) { |
c223da83 | 176 | dprint(FD_TIME, "CPU clock going back in time\n"); |
93f0b09a JA |
177 | t = tv->last_cycles; |
178 | } else if (tv) | |
179 | tv->last_cycles = t; | |
c223da83 | 180 | |
71339117 | 181 | usecs = (t * inv_cycles_per_usec) / 16777216UL; |
c223da83 JA |
182 | tp->tv_sec = usecs / 1000000; |
183 | tp->tv_usec = usecs % 1000000; | |
c223da83 JA |
184 | break; |
185 | } | |
186 | #endif | |
187 | default: | |
188 | log_err("fio: invalid clock source %d\n", fio_clock_source); | |
189 | break; | |
02bcaa8c | 190 | } |
3e488920 JA |
191 | |
192 | /* | |
193 | * If Linux is using the tsc clock on non-synced processors, | |
194 | * sometimes time can appear to drift backwards. Fix that up. | |
195 | */ | |
93f0b09a JA |
196 | if (tv) { |
197 | if (tv->last_tv_valid) { | |
198 | if (tp->tv_sec < tv->last_tv.tv_sec) | |
199 | tp->tv_sec = tv->last_tv.tv_sec; | |
200 | else if (tv->last_tv.tv_sec == tp->tv_sec && | |
201 | tp->tv_usec < tv->last_tv.tv_usec) | |
202 | tp->tv_usec = tv->last_tv.tv_usec; | |
5d879392 | 203 | } |
93f0b09a JA |
204 | tv->last_tv_valid = 1; |
205 | memcpy(&tv->last_tv, tp, sizeof(*tp)); | |
3e488920 | 206 | } |
02bcaa8c | 207 | } |
be4ecfdf | 208 | |
09a32402 | 209 | #ifdef ARCH_HAVE_CPU_CLOCK |
c223da83 JA |
210 | static unsigned long get_cycles_per_usec(void) |
211 | { | |
9ff1c070 | 212 | struct timespec ts; |
c223da83 JA |
213 | struct timeval s, e; |
214 | unsigned long long c_s, c_e; | |
215 | ||
9ff1c070 JA |
216 | fill_clock_gettime(&ts); |
217 | s.tv_sec = ts.tv_sec; | |
218 | s.tv_usec = ts.tv_nsec / 1000; | |
219 | ||
c223da83 JA |
220 | c_s = get_cpu_clock(); |
221 | do { | |
222 | unsigned long long elapsed; | |
223 | ||
9ff1c070 JA |
224 | fill_clock_gettime(&ts); |
225 | e.tv_sec = ts.tv_sec; | |
226 | e.tv_usec = ts.tv_nsec / 1000; | |
227 | ||
c223da83 | 228 | elapsed = utime_since(&s, &e); |
486332e5 | 229 | if (elapsed >= 1280) { |
c223da83 JA |
230 | c_e = get_cpu_clock(); |
231 | break; | |
232 | } | |
233 | } while (1); | |
234 | ||
c011000d | 235 | return (c_e - c_s + 127) >> 7; |
c223da83 JA |
236 | } |
237 | ||
fa80feae JA |
238 | #define NR_TIME_ITERS 50 |
239 | ||
09a32402 | 240 | static void calibrate_cpu_clock(void) |
c223da83 JA |
241 | { |
242 | double delta, mean, S; | |
fa80feae | 243 | unsigned long avg, cycles[NR_TIME_ITERS]; |
c223da83 JA |
244 | int i, samples; |
245 | ||
c223da83 JA |
246 | cycles[0] = get_cycles_per_usec(); |
247 | S = delta = mean = 0.0; | |
fa80feae | 248 | for (i = 0; i < NR_TIME_ITERS; i++) { |
c223da83 JA |
249 | cycles[i] = get_cycles_per_usec(); |
250 | delta = cycles[i] - mean; | |
251 | if (delta) { | |
252 | mean += delta / (i + 1.0); | |
253 | S += delta * (cycles[i] - mean); | |
254 | } | |
255 | } | |
256 | ||
fa80feae | 257 | S = sqrt(S / (NR_TIME_ITERS - 1.0)); |
c223da83 JA |
258 | |
259 | samples = avg = 0; | |
fa80feae | 260 | for (i = 0; i < NR_TIME_ITERS; i++) { |
c223da83 JA |
261 | double this = cycles[i]; |
262 | ||
03e20d68 | 263 | if ((fmax(this, mean) - fmin(this, mean)) > S) |
c223da83 JA |
264 | continue; |
265 | samples++; | |
266 | avg += this; | |
267 | } | |
268 | ||
fa80feae | 269 | S /= (double) NR_TIME_ITERS; |
89db727d | 270 | mean /= 10.0; |
c223da83 | 271 | |
fa80feae | 272 | for (i = 0; i < NR_TIME_ITERS; i++) |
c223da83 JA |
273 | dprint(FD_TIME, "cycles[%d]=%lu\n", i, cycles[i] / 10); |
274 | ||
d7abad3d | 275 | avg /= samples; |
b0ff22d7 | 276 | avg = (avg + 5) / 10; |
c223da83 JA |
277 | dprint(FD_TIME, "avg: %lu\n", avg); |
278 | dprint(FD_TIME, "mean=%f, S=%f\n", mean, S); | |
279 | ||
280 | cycles_per_usec = avg; | |
71339117 JA |
281 | inv_cycles_per_usec = 16777216UL / cycles_per_usec; |
282 | dprint(FD_TIME, "inv_cycles_per_usec=%lu\n", inv_cycles_per_usec); | |
09a32402 JA |
283 | } |
284 | #else | |
285 | static void calibrate_cpu_clock(void) | |
286 | { | |
287 | } | |
288 | #endif | |
289 | ||
5d879392 JA |
290 | void fio_local_clock_init(int is_thread) |
291 | { | |
292 | struct tv_valid *t; | |
293 | ||
294 | t = calloc(sizeof(*t), 1); | |
295 | if (pthread_setspecific(tv_tls_key, t)) | |
296 | log_err("fio: can't set TLS key\n"); | |
297 | } | |
298 | ||
299 | static void kill_tv_tls_key(void *data) | |
300 | { | |
301 | free(data); | |
302 | } | |
303 | ||
09a32402 JA |
304 | void fio_clock_init(void) |
305 | { | |
01423eae JA |
306 | if (fio_clock_source == fio_clock_source_inited) |
307 | return; | |
308 | ||
5d879392 JA |
309 | if (pthread_key_create(&tv_tls_key, kill_tv_tls_key)) |
310 | log_err("fio: can't create TLS key\n"); | |
311 | ||
01423eae | 312 | fio_clock_source_inited = fio_clock_source; |
09a32402 | 313 | calibrate_cpu_clock(); |
fa80feae JA |
314 | |
315 | /* | |
316 | * If the arch sets tsc_reliable != 0, then it must be good enough | |
317 | * to use as THE clock source. For x86 CPUs, this means the TSC | |
318 | * runs at a constant rate and is synced across CPU cores. | |
319 | */ | |
320 | if (tsc_reliable) { | |
321 | if (!fio_clock_source_set) | |
322 | fio_clock_source = CS_CPUCLOCK; | |
323 | } else if (fio_clock_source == CS_CPUCLOCK) | |
324 | log_info("fio: clocksource=cpu may not be reliable\n"); | |
c223da83 JA |
325 | } |
326 | ||
aa60bc58 | 327 | uint64_t utime_since(struct timeval *s, struct timeval *e) |
be4ecfdf | 328 | { |
39ab7da2 | 329 | long sec, usec; |
aa60bc58 | 330 | uint64_t ret; |
39ab7da2 JA |
331 | |
332 | sec = e->tv_sec - s->tv_sec; | |
333 | usec = e->tv_usec - s->tv_usec; | |
334 | if (sec > 0 && usec < 0) { | |
335 | sec--; | |
336 | usec += 1000000; | |
337 | } | |
338 | ||
339 | /* | |
340 | * time warp bug on some kernels? | |
341 | */ | |
342 | if (sec < 0 || (sec == 0 && usec < 0)) | |
343 | return 0; | |
344 | ||
345 | ret = sec * 1000000ULL + usec; | |
346 | ||
347 | return ret; | |
be4ecfdf JA |
348 | } |
349 | ||
aa60bc58 | 350 | uint64_t utime_since_now(struct timeval *s) |
be4ecfdf | 351 | { |
39ab7da2 JA |
352 | struct timeval t; |
353 | ||
354 | fio_gettime(&t, NULL); | |
355 | return utime_since(s, &t); | |
be4ecfdf | 356 | } |
783a3eb1 | 357 | |
aa60bc58 | 358 | uint64_t mtime_since(struct timeval *s, struct timeval *e) |
783a3eb1 | 359 | { |
39ab7da2 | 360 | long sec, usec, ret; |
783a3eb1 | 361 | |
39ab7da2 JA |
362 | sec = e->tv_sec - s->tv_sec; |
363 | usec = e->tv_usec - s->tv_usec; | |
364 | if (sec > 0 && usec < 0) { | |
365 | sec--; | |
366 | usec += 1000000; | |
783a3eb1 JA |
367 | } |
368 | ||
39ab7da2 JA |
369 | if (sec < 0 || (sec == 0 && usec < 0)) |
370 | return 0; | |
371 | ||
372 | sec *= 1000UL; | |
373 | usec /= 1000UL; | |
374 | ret = sec + usec; | |
375 | ||
376 | return ret; | |
783a3eb1 JA |
377 | } |
378 | ||
aa60bc58 | 379 | uint64_t mtime_since_now(struct timeval *s) |
783a3eb1 | 380 | { |
39ab7da2 JA |
381 | struct timeval t; |
382 | void *p = __builtin_return_address(0); | |
783a3eb1 | 383 | |
39ab7da2 JA |
384 | fio_gettime(&t, p); |
385 | return mtime_since(s, &t); | |
386 | } | |
783a3eb1 | 387 | |
aa60bc58 | 388 | uint64_t time_since_now(struct timeval *s) |
39ab7da2 JA |
389 | { |
390 | return mtime_since_now(s) / 1000; | |
783a3eb1 | 391 | } |
7d11f871 JA |
392 | |
393 | #if defined(FIO_HAVE_CPU_AFFINITY) && defined(ARCH_HAVE_CPU_CLOCK) | |
394 | ||
395 | #define CLOCK_ENTRIES 100000 | |
396 | ||
397 | struct clock_entry { | |
398 | unsigned long seq; | |
399 | unsigned long tsc; | |
400 | unsigned long cpu; | |
401 | }; | |
402 | ||
403 | struct clock_thread { | |
404 | pthread_t thread; | |
405 | int cpu; | |
406 | pthread_mutex_t lock; | |
407 | pthread_mutex_t started; | |
408 | uint64_t *seq; | |
409 | struct clock_entry *entries; | |
410 | }; | |
411 | ||
412 | static inline uint64_t atomic64_inc_return(uint64_t *seq) | |
413 | { | |
414 | return 1 + __sync_fetch_and_add(seq, 1); | |
415 | } | |
416 | ||
417 | static void *clock_thread_fn(void *data) | |
418 | { | |
419 | struct clock_thread *t = data; | |
420 | struct clock_entry *c; | |
421 | os_cpu_mask_t cpu_mask; | |
422 | int i; | |
423 | ||
424 | memset(&cpu_mask, 0, sizeof(cpu_mask)); | |
425 | fio_cpu_set(&cpu_mask, t->cpu); | |
426 | ||
427 | if (fio_setaffinity(gettid(), cpu_mask) == -1) { | |
428 | log_err("clock setaffinity failed\n"); | |
429 | return (void *) 1; | |
430 | } | |
431 | ||
7d11f871 | 432 | pthread_mutex_lock(&t->lock); |
b9b3498e | 433 | pthread_mutex_unlock(&t->started); |
7d11f871 JA |
434 | |
435 | c = &t->entries[0]; | |
436 | for (i = 0; i < CLOCK_ENTRIES; i++, c++) { | |
437 | uint64_t seq, tsc; | |
438 | ||
439 | c->cpu = t->cpu; | |
440 | do { | |
441 | seq = atomic64_inc_return(t->seq); | |
442 | tsc = get_cpu_clock(); | |
443 | } while (seq != *t->seq); | |
444 | ||
445 | c->seq = seq; | |
446 | c->tsc = tsc; | |
447 | } | |
448 | ||
449 | log_info("cs: cpu%3d: %lu clocks seen\n", t->cpu, t->entries[CLOCK_ENTRIES - 1].tsc - t->entries[0].tsc); | |
450 | return NULL; | |
451 | } | |
452 | ||
453 | static int clock_cmp(const void *p1, const void *p2) | |
454 | { | |
455 | const struct clock_entry *c1 = p1; | |
456 | const struct clock_entry *c2 = p2; | |
457 | ||
b9b3498e JA |
458 | if (c1->seq == c2->seq) |
459 | log_err("cs: bug in atomic sequence!\n"); | |
460 | ||
7d11f871 JA |
461 | return c1->seq - c2->seq; |
462 | } | |
463 | ||
464 | int fio_monotonic_clocktest(void) | |
465 | { | |
466 | struct clock_thread *threads; | |
467 | unsigned int nr_cpus = cpus_online(); | |
468 | struct clock_entry *entries; | |
469 | unsigned long tentries, failed; | |
470 | uint64_t seq = 0; | |
471 | int i; | |
472 | ||
4f1d43c2 JA |
473 | fio_debug |= 1U << FD_TIME; |
474 | calibrate_cpu_clock(); | |
475 | fio_debug &= ~(1U << FD_TIME); | |
476 | ||
7d11f871 JA |
477 | threads = malloc(nr_cpus * sizeof(struct clock_thread)); |
478 | tentries = CLOCK_ENTRIES * nr_cpus; | |
479 | entries = malloc(tentries * sizeof(struct clock_entry)); | |
480 | ||
481 | log_info("cs: Testing %u CPUs\n", nr_cpus); | |
482 | ||
483 | for (i = 0; i < nr_cpus; i++) { | |
484 | struct clock_thread *t = &threads[i]; | |
485 | ||
486 | t->cpu = i; | |
487 | t->seq = &seq; | |
488 | t->entries = &entries[i * CLOCK_ENTRIES]; | |
489 | pthread_mutex_init(&t->lock, NULL); | |
490 | pthread_mutex_init(&t->started, NULL); | |
491 | pthread_mutex_lock(&t->lock); | |
492 | pthread_create(&t->thread, NULL, clock_thread_fn, t); | |
493 | } | |
494 | ||
495 | for (i = 0; i < nr_cpus; i++) { | |
496 | struct clock_thread *t = &threads[i]; | |
497 | ||
498 | pthread_mutex_lock(&t->started); | |
499 | } | |
500 | ||
501 | for (i = 0; i < nr_cpus; i++) { | |
502 | struct clock_thread *t = &threads[i]; | |
503 | ||
504 | pthread_mutex_unlock(&t->lock); | |
505 | } | |
506 | ||
507 | for (failed = i = 0; i < nr_cpus; i++) { | |
508 | struct clock_thread *t = &threads[i]; | |
509 | void *ret; | |
510 | ||
511 | pthread_join(t->thread, &ret); | |
512 | if (ret) | |
513 | failed++; | |
514 | } | |
515 | free(threads); | |
516 | ||
517 | if (failed) { | |
518 | log_err("Clocksource test: %u threads failed\n", failed); | |
519 | goto err; | |
520 | } | |
521 | ||
522 | qsort(entries, tentries, sizeof(struct clock_entry), clock_cmp); | |
523 | ||
524 | for (failed = i = 0; i < tentries; i++) { | |
525 | struct clock_entry *prev, *this = &entries[i]; | |
526 | ||
527 | if (!i) { | |
528 | prev = this; | |
529 | continue; | |
530 | } | |
531 | ||
532 | if (prev->tsc > this->tsc) { | |
533 | uint64_t diff = prev->tsc - this->tsc; | |
534 | ||
535 | log_info("cs: CPU clock mismatch (diff=%lu):\n", diff); | |
536 | log_info("\t CPU%3lu: TSC=%lu, SEQ=%lu\n", prev->cpu, prev->tsc, prev->seq); | |
537 | log_info("\t CPU%3lu: TSC=%lu, SEQ=%lu\n", this->cpu, this->tsc, this->seq); | |
538 | failed++; | |
539 | } | |
540 | ||
541 | prev = this; | |
542 | } | |
543 | ||
544 | if (failed) | |
545 | log_info("cs: Failed: %lu\n", failed); | |
546 | else | |
547 | log_info("cs: Pass!\n"); | |
548 | ||
549 | err: | |
550 | free(entries); | |
551 | return !!failed; | |
552 | } | |
553 | ||
554 | #else /* defined(FIO_HAVE_CPU_AFFINITY) && defined(ARCH_HAVE_CPU_CLOCK) */ | |
555 | ||
556 | int fio_monotonic_clocktest(void) | |
557 | { | |
558 | log_info("cs: current platform does not support CPU clocks\n"); | |
559 | return 0; | |
560 | } | |
561 | ||
562 | #endif |