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