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