Home | History | Annotate | Download | only in fio
      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 #if defined(ARCH_HAVE_CPU_CLOCK)
     17 #ifndef ARCH_CPU_CLOCK_CYCLES_PER_USEC
     18 static unsigned long cycles_per_usec;
     19 static unsigned long inv_cycles_per_usec;
     20 static uint64_t max_cycles_for_mult;
     21 #endif
     22 #ifdef ARCH_CPU_CLOCK_WRAPS
     23 static unsigned long long cycles_start, cycles_wrap;
     24 #endif
     25 #endif
     26 int tsc_reliable = 0;
     27 
     28 struct tv_valid {
     29 	uint64_t last_cycles;
     30 	int last_tv_valid;
     31 	int warned;
     32 };
     33 #ifdef ARCH_HAVE_CPU_CLOCK
     34 #ifdef CONFIG_TLS_THREAD
     35 static __thread struct tv_valid static_tv_valid;
     36 #else
     37 static pthread_key_t tv_tls_key;
     38 #endif
     39 #endif
     40 
     41 enum fio_cs fio_clock_source = FIO_PREFERRED_CLOCK_SOURCE;
     42 int fio_clock_source_set = 0;
     43 static enum fio_cs fio_clock_source_inited = CS_INVAL;
     44 
     45 #ifdef FIO_DEBUG_TIME
     46 
     47 #define HASH_BITS	8
     48 #define HASH_SIZE	(1 << HASH_BITS)
     49 
     50 static struct flist_head hash[HASH_SIZE];
     51 static int gtod_inited;
     52 
     53 struct gtod_log {
     54 	struct flist_head list;
     55 	void *caller;
     56 	unsigned long calls;
     57 };
     58 
     59 static struct gtod_log *find_hash(void *caller)
     60 {
     61 	unsigned long h = hash_ptr(caller, HASH_BITS);
     62 	struct flist_head *entry;
     63 
     64 	flist_for_each(entry, &hash[h]) {
     65 		struct gtod_log *log = flist_entry(entry, struct gtod_log,
     66 									list);
     67 
     68 		if (log->caller == caller)
     69 			return log;
     70 	}
     71 
     72 	return NULL;
     73 }
     74 
     75 static void inc_caller(void *caller)
     76 {
     77 	struct gtod_log *log = find_hash(caller);
     78 
     79 	if (!log) {
     80 		unsigned long h;
     81 
     82 		log = malloc(sizeof(*log));
     83 		INIT_FLIST_HEAD(&log->list);
     84 		log->caller = caller;
     85 		log->calls = 0;
     86 
     87 		h = hash_ptr(caller, HASH_BITS);
     88 		flist_add_tail(&log->list, &hash[h]);
     89 	}
     90 
     91 	log->calls++;
     92 }
     93 
     94 static void gtod_log_caller(void *caller)
     95 {
     96 	if (gtod_inited)
     97 		inc_caller(caller);
     98 }
     99 
    100 static void fio_exit fio_dump_gtod(void)
    101 {
    102 	unsigned long total_calls = 0;
    103 	int i;
    104 
    105 	for (i = 0; i < HASH_SIZE; i++) {
    106 		struct flist_head *entry;
    107 		struct gtod_log *log;
    108 
    109 		flist_for_each(entry, &hash[i]) {
    110 			log = flist_entry(entry, struct gtod_log, list);
    111 
    112 			printf("function %p, calls %lu\n", log->caller,
    113 								log->calls);
    114 			total_calls += log->calls;
    115 		}
    116 	}
    117 
    118 	printf("Total %lu gettimeofday\n", total_calls);
    119 }
    120 
    121 static void fio_init gtod_init(void)
    122 {
    123 	int i;
    124 
    125 	for (i = 0; i < HASH_SIZE; i++)
    126 		INIT_FLIST_HEAD(&hash[i]);
    127 
    128 	gtod_inited = 1;
    129 }
    130 
    131 #endif /* FIO_DEBUG_TIME */
    132 
    133 #ifdef CONFIG_CLOCK_GETTIME
    134 static int fill_clock_gettime(struct timespec *ts)
    135 {
    136 #if defined(CONFIG_CLOCK_MONOTONIC_RAW)
    137 	return clock_gettime(CLOCK_MONOTONIC_RAW, ts);
    138 #elif defined(CONFIG_CLOCK_MONOTONIC)
    139 	return clock_gettime(CLOCK_MONOTONIC, ts);
    140 #else
    141 	return clock_gettime(CLOCK_REALTIME, ts);
    142 #endif
    143 }
    144 #endif
    145 
    146 static void __fio_gettime(struct timeval *tp)
    147 {
    148 	switch (fio_clock_source) {
    149 #ifdef CONFIG_GETTIMEOFDAY
    150 	case CS_GTOD:
    151 		gettimeofday(tp, NULL);
    152 		break;
    153 #endif
    154 #ifdef CONFIG_CLOCK_GETTIME
    155 	case CS_CGETTIME: {
    156 		struct timespec ts;
    157 
    158 		if (fill_clock_gettime(&ts) < 0) {
    159 			log_err("fio: clock_gettime fails\n");
    160 			assert(0);
    161 		}
    162 
    163 		tp->tv_sec = ts.tv_sec;
    164 		tp->tv_usec = ts.tv_nsec / 1000;
    165 		break;
    166 		}
    167 #endif
    168 #ifdef ARCH_HAVE_CPU_CLOCK
    169 	case CS_CPUCLOCK: {
    170 		uint64_t usecs, t;
    171 		struct tv_valid *tv;
    172 
    173 #ifdef CONFIG_TLS_THREAD
    174 		tv = &static_tv_valid;
    175 #else
    176 		tv = pthread_getspecific(tv_tls_key);
    177 #endif
    178 
    179 		t = get_cpu_clock();
    180 #ifdef ARCH_CPU_CLOCK_WRAPS
    181 		if (t < cycles_start && !cycles_wrap)
    182 			cycles_wrap = 1;
    183 		else if (cycles_wrap && t >= cycles_start && !tv->warned) {
    184 			log_err("fio: double CPU clock wrap\n");
    185 			tv->warned = 1;
    186 		}
    187 
    188 		t -= cycles_start;
    189 #endif
    190 		tv->last_cycles = t;
    191 		tv->last_tv_valid = 1;
    192 #ifdef ARCH_CPU_CLOCK_CYCLES_PER_USEC
    193 		usecs = t / ARCH_CPU_CLOCK_CYCLES_PER_USEC;
    194 #else
    195 		if (t < max_cycles_for_mult)
    196 			usecs = (t * inv_cycles_per_usec) / 16777216UL;
    197 		else
    198 			usecs = t / cycles_per_usec;
    199 #endif
    200 		tp->tv_sec = usecs / 1000000;
    201 		tp->tv_usec = usecs % 1000000;
    202 		break;
    203 		}
    204 #endif
    205 	default:
    206 		log_err("fio: invalid clock source %d\n", fio_clock_source);
    207 		break;
    208 	}
    209 }
    210 
    211 #ifdef FIO_DEBUG_TIME
    212 void fio_gettime(struct timeval *tp, void *caller)
    213 #else
    214 void fio_gettime(struct timeval *tp, void fio_unused *caller)
    215 #endif
    216 {
    217 #ifdef FIO_DEBUG_TIME
    218 	if (!caller)
    219 		caller = __builtin_return_address(0);
    220 
    221 	gtod_log_caller(caller);
    222 #endif
    223 	if (fio_unlikely(fio_gettime_offload(tp)))
    224 		return;
    225 
    226 	__fio_gettime(tp);
    227 }
    228 
    229 #if defined(ARCH_HAVE_CPU_CLOCK) && !defined(ARCH_CPU_CLOCK_CYCLES_PER_USEC)
    230 static unsigned long get_cycles_per_usec(void)
    231 {
    232 	struct timeval s, e;
    233 	uint64_t c_s, c_e;
    234 	enum fio_cs old_cs = fio_clock_source;
    235 	uint64_t elapsed;
    236 
    237 #ifdef CONFIG_CLOCK_GETTIME
    238 	fio_clock_source = CS_CGETTIME;
    239 #else
    240 	fio_clock_source = CS_GTOD;
    241 #endif
    242 	__fio_gettime(&s);
    243 
    244 	c_s = get_cpu_clock();
    245 	do {
    246 		__fio_gettime(&e);
    247 
    248 		elapsed = utime_since(&s, &e);
    249 		if (elapsed >= 1280) {
    250 			c_e = get_cpu_clock();
    251 			break;
    252 		}
    253 	} while (1);
    254 
    255 	fio_clock_source = old_cs;
    256 	return (c_e - c_s) / elapsed;
    257 }
    258 
    259 #define NR_TIME_ITERS	50
    260 
    261 static int calibrate_cpu_clock(void)
    262 {
    263 	double delta, mean, S;
    264 	uint64_t minc, maxc, avg, cycles[NR_TIME_ITERS];
    265 	int i, samples;
    266 
    267 	cycles[0] = get_cycles_per_usec();
    268 	S = delta = mean = 0.0;
    269 	for (i = 0; i < NR_TIME_ITERS; i++) {
    270 		cycles[i] = get_cycles_per_usec();
    271 		delta = cycles[i] - mean;
    272 		if (delta) {
    273 			mean += delta / (i + 1.0);
    274 			S += delta * (cycles[i] - mean);
    275 		}
    276 	}
    277 
    278 	/*
    279 	 * The most common platform clock breakage is returning zero
    280 	 * indefinitely. Check for that and return failure.
    281 	 */
    282 	if (!cycles[0] && !cycles[NR_TIME_ITERS - 1])
    283 		return 1;
    284 
    285 	S = sqrt(S / (NR_TIME_ITERS - 1.0));
    286 
    287 	minc = -1ULL;
    288 	maxc = samples = avg = 0;
    289 	for (i = 0; i < NR_TIME_ITERS; i++) {
    290 		double this = cycles[i];
    291 
    292 		minc = min(cycles[i], minc);
    293 		maxc = max(cycles[i], maxc);
    294 
    295 		if ((fmax(this, mean) - fmin(this, mean)) > S)
    296 			continue;
    297 		samples++;
    298 		avg += this;
    299 	}
    300 
    301 	S /= (double) NR_TIME_ITERS;
    302 
    303 	for (i = 0; i < NR_TIME_ITERS; i++)
    304 		dprint(FD_TIME, "cycles[%d]=%llu\n", i, (unsigned long long) cycles[i]);
    305 
    306 	avg /= samples;
    307 	dprint(FD_TIME, "avg: %llu\n", (unsigned long long) avg);
    308 	dprint(FD_TIME, "min=%llu, max=%llu, mean=%f, S=%f\n",
    309 			(unsigned long long) minc,
    310 			(unsigned long long) maxc, mean, S);
    311 
    312 	cycles_per_usec = avg;
    313 	inv_cycles_per_usec = 16777216UL / cycles_per_usec;
    314 	max_cycles_for_mult = ~0ULL / inv_cycles_per_usec;
    315 	dprint(FD_TIME, "inv_cycles_per_usec=%lu\n", inv_cycles_per_usec);
    316 #ifdef ARCH_CPU_CLOCK_WRAPS
    317 	cycles_start = get_cpu_clock();
    318 	dprint(FD_TIME, "cycles_start=%llu\n", cycles_start);
    319 #endif
    320 	return 0;
    321 }
    322 #else
    323 static int calibrate_cpu_clock(void)
    324 {
    325 #ifdef ARCH_CPU_CLOCK_CYCLES_PER_USEC
    326 	return 0;
    327 #else
    328 	return 1;
    329 #endif
    330 }
    331 #endif // ARCH_HAVE_CPU_CLOCK
    332 
    333 #ifndef CONFIG_TLS_THREAD
    334 void fio_local_clock_init(int is_thread)
    335 {
    336 	struct tv_valid *t;
    337 
    338 	t = calloc(1, sizeof(*t));
    339 	if (pthread_setspecific(tv_tls_key, t)) {
    340 		log_err("fio: can't set TLS key\n");
    341 		assert(0);
    342 	}
    343 }
    344 
    345 static void kill_tv_tls_key(void *data)
    346 {
    347 	free(data);
    348 }
    349 #else
    350 void fio_local_clock_init(int is_thread)
    351 {
    352 }
    353 #endif
    354 
    355 void fio_clock_init(void)
    356 {
    357 	if (fio_clock_source == fio_clock_source_inited)
    358 		return;
    359 
    360 #ifndef CONFIG_TLS_THREAD
    361 	if (pthread_key_create(&tv_tls_key, kill_tv_tls_key))
    362 		log_err("fio: can't create TLS key\n");
    363 #endif
    364 
    365 	fio_clock_source_inited = fio_clock_source;
    366 
    367 	if (calibrate_cpu_clock())
    368 		tsc_reliable = 0;
    369 
    370 	/*
    371 	 * If the arch sets tsc_reliable != 0, then it must be good enough
    372 	 * to use as THE clock source. For x86 CPUs, this means the TSC
    373 	 * runs at a constant rate and is synced across CPU cores.
    374 	 */
    375 	if (tsc_reliable) {
    376 		if (!fio_clock_source_set && !fio_monotonic_clocktest(0))
    377 			fio_clock_source = CS_CPUCLOCK;
    378 	} else if (fio_clock_source == CS_CPUCLOCK)
    379 		log_info("fio: clocksource=cpu may not be reliable\n");
    380 }
    381 
    382 uint64_t utime_since(const struct timeval *s, const struct timeval *e)
    383 {
    384 	int64_t sec, usec;
    385 
    386 	sec = e->tv_sec - s->tv_sec;
    387 	usec = e->tv_usec - s->tv_usec;
    388 	if (sec > 0 && usec < 0) {
    389 		sec--;
    390 		usec += 1000000;
    391 	}
    392 
    393 	/*
    394 	 * time warp bug on some kernels?
    395 	 */
    396 	if (sec < 0 || (sec == 0 && usec < 0))
    397 		return 0;
    398 
    399 	return usec + (sec * 1000000);
    400 }
    401 
    402 uint64_t utime_since_now(const struct timeval *s)
    403 {
    404 	struct timeval t;
    405 #ifdef FIO_DEBUG_TIME
    406 	void *p = __builtin_return_address(0);
    407 
    408 	fio_gettime(&t, p);
    409 #else
    410 	fio_gettime(&t, NULL);
    411 #endif
    412 
    413 	return utime_since(s, &t);
    414 }
    415 
    416 uint64_t mtime_since(const struct timeval *s, const struct timeval *e)
    417 {
    418 	long sec, usec;
    419 
    420 	sec = e->tv_sec - s->tv_sec;
    421 	usec = e->tv_usec - s->tv_usec;
    422 	if (sec > 0 && usec < 0) {
    423 		sec--;
    424 		usec += 1000000;
    425 	}
    426 
    427 	if (sec < 0 || (sec == 0 && usec < 0))
    428 		return 0;
    429 
    430 	sec *= 1000;
    431 	usec /= 1000;
    432 	return sec + usec;
    433 }
    434 
    435 uint64_t mtime_since_now(const struct timeval *s)
    436 {
    437 	struct timeval t;
    438 #ifdef FIO_DEBUG_TIME
    439 	void *p = __builtin_return_address(0);
    440 
    441 	fio_gettime(&t, p);
    442 #else
    443 	fio_gettime(&t, NULL);
    444 #endif
    445 
    446 	return mtime_since(s, &t);
    447 }
    448 
    449 uint64_t time_since_now(const struct timeval *s)
    450 {
    451 	return mtime_since_now(s) / 1000;
    452 }
    453 
    454 #if defined(FIO_HAVE_CPU_AFFINITY) && defined(ARCH_HAVE_CPU_CLOCK)  && \
    455     defined(CONFIG_SFAA)
    456 
    457 #define CLOCK_ENTRIES_DEBUG	100000
    458 #define CLOCK_ENTRIES_TEST	10000
    459 
    460 struct clock_entry {
    461 	uint32_t seq;
    462 	uint32_t cpu;
    463 	uint64_t tsc;
    464 };
    465 
    466 struct clock_thread {
    467 	pthread_t thread;
    468 	int cpu;
    469 	int debug;
    470 	pthread_mutex_t lock;
    471 	pthread_mutex_t started;
    472 	unsigned long nr_entries;
    473 	uint32_t *seq;
    474 	struct clock_entry *entries;
    475 };
    476 
    477 static inline uint32_t atomic32_inc_return(uint32_t *seq)
    478 {
    479 	return 1 + __sync_fetch_and_add(seq, 1);
    480 }
    481 
    482 static void *clock_thread_fn(void *data)
    483 {
    484 	struct clock_thread *t = data;
    485 	struct clock_entry *c;
    486 	os_cpu_mask_t cpu_mask;
    487 	uint32_t last_seq;
    488 	unsigned long long first;
    489 	int i;
    490 
    491 	if (fio_cpuset_init(&cpu_mask)) {
    492 		int __err = errno;
    493 
    494 		log_err("clock cpuset init failed: %s\n", strerror(__err));
    495 		goto err_out;
    496 	}
    497 
    498 	fio_cpu_set(&cpu_mask, t->cpu);
    499 
    500 	if (fio_setaffinity(gettid(), cpu_mask) == -1) {
    501 		int __err = errno;
    502 
    503 		log_err("clock setaffinity failed: %s\n", strerror(__err));
    504 		goto err;
    505 	}
    506 
    507 	pthread_mutex_lock(&t->lock);
    508 	pthread_mutex_unlock(&t->started);
    509 
    510 	first = get_cpu_clock();
    511 	last_seq = 0;
    512 	c = &t->entries[0];
    513 	for (i = 0; i < t->nr_entries; i++, c++) {
    514 		uint32_t seq;
    515 		uint64_t tsc;
    516 
    517 		c->cpu = t->cpu;
    518 		do {
    519 			seq = atomic32_inc_return(t->seq);
    520 			if (seq < last_seq)
    521 				break;
    522 			tsc = get_cpu_clock();
    523 		} while (seq != *t->seq);
    524 
    525 		c->seq = seq;
    526 		c->tsc = tsc;
    527 	}
    528 
    529 	if (t->debug) {
    530 		unsigned long long clocks;
    531 
    532 		clocks = t->entries[i - 1].tsc - t->entries[0].tsc;
    533 		log_info("cs: cpu%3d: %llu clocks seen, first %llu\n", t->cpu,
    534 							clocks, first);
    535 	}
    536 
    537 	/*
    538 	 * The most common platform clock breakage is returning zero
    539 	 * indefinitely. Check for that and return failure.
    540 	 */
    541 	if (!t->entries[i - 1].tsc && !t->entries[0].tsc)
    542 		goto err;
    543 
    544 	fio_cpuset_exit(&cpu_mask);
    545 	return NULL;
    546 err:
    547 	fio_cpuset_exit(&cpu_mask);
    548 err_out:
    549 	return (void *) 1;
    550 }
    551 
    552 static int clock_cmp(const void *p1, const void *p2)
    553 {
    554 	const struct clock_entry *c1 = p1;
    555 	const struct clock_entry *c2 = p2;
    556 
    557 	if (c1->seq == c2->seq)
    558 		log_err("cs: bug in atomic sequence!\n");
    559 
    560 	return c1->seq - c2->seq;
    561 }
    562 
    563 int fio_monotonic_clocktest(int debug)
    564 {
    565 	struct clock_thread *cthreads;
    566 	unsigned int nr_cpus = cpus_online();
    567 	struct clock_entry *entries;
    568 	unsigned long nr_entries, tentries, failed = 0;
    569 	struct clock_entry *prev, *this;
    570 	uint32_t seq = 0;
    571 	unsigned int i;
    572 
    573 	if (debug) {
    574 		log_info("cs: reliable_tsc: %s\n", tsc_reliable ? "yes" : "no");
    575 
    576 #ifdef FIO_INC_DEBUG
    577 		fio_debug |= 1U << FD_TIME;
    578 #endif
    579 		nr_entries = CLOCK_ENTRIES_DEBUG;
    580 	} else
    581 		nr_entries = CLOCK_ENTRIES_TEST;
    582 
    583 	calibrate_cpu_clock();
    584 
    585 	if (debug) {
    586 #ifdef FIO_INC_DEBUG
    587 		fio_debug &= ~(1U << FD_TIME);
    588 #endif
    589 	}
    590 
    591 	cthreads = malloc(nr_cpus * sizeof(struct clock_thread));
    592 	tentries = nr_entries * nr_cpus;
    593 	entries = malloc(tentries * sizeof(struct clock_entry));
    594 
    595 	if (debug)
    596 		log_info("cs: Testing %u CPUs\n", nr_cpus);
    597 
    598 	for (i = 0; i < nr_cpus; i++) {
    599 		struct clock_thread *t = &cthreads[i];
    600 
    601 		t->cpu = i;
    602 		t->debug = debug;
    603 		t->seq = &seq;
    604 		t->nr_entries = nr_entries;
    605 		t->entries = &entries[i * nr_entries];
    606 		pthread_mutex_init(&t->lock, NULL);
    607 		pthread_mutex_init(&t->started, NULL);
    608 		pthread_mutex_lock(&t->lock);
    609 		if (pthread_create(&t->thread, NULL, clock_thread_fn, t)) {
    610 			failed++;
    611 			nr_cpus = i;
    612 			break;
    613 		}
    614 	}
    615 
    616 	for (i = 0; i < nr_cpus; i++) {
    617 		struct clock_thread *t = &cthreads[i];
    618 
    619 		pthread_mutex_lock(&t->started);
    620 	}
    621 
    622 	for (i = 0; i < nr_cpus; i++) {
    623 		struct clock_thread *t = &cthreads[i];
    624 
    625 		pthread_mutex_unlock(&t->lock);
    626 	}
    627 
    628 	for (i = 0; i < nr_cpus; i++) {
    629 		struct clock_thread *t = &cthreads[i];
    630 		void *ret;
    631 
    632 		pthread_join(t->thread, &ret);
    633 		if (ret)
    634 			failed++;
    635 	}
    636 	free(cthreads);
    637 
    638 	if (failed) {
    639 		if (debug)
    640 			log_err("Clocksource test: %lu threads failed\n", failed);
    641 		goto err;
    642 	}
    643 
    644 	qsort(entries, tentries, sizeof(struct clock_entry), clock_cmp);
    645 
    646 	/* silence silly gcc */
    647 	prev = NULL;
    648 	for (failed = i = 0; i < tentries; i++) {
    649 		this = &entries[i];
    650 
    651 		if (!i) {
    652 			prev = this;
    653 			continue;
    654 		}
    655 
    656 		if (prev->tsc > this->tsc) {
    657 			uint64_t diff = prev->tsc - this->tsc;
    658 
    659 			if (!debug) {
    660 				failed++;
    661 				break;
    662 			}
    663 
    664 			log_info("cs: CPU clock mismatch (diff=%llu):\n",
    665 						(unsigned long long) diff);
    666 			log_info("\t CPU%3u: TSC=%llu, SEQ=%u\n", prev->cpu, (unsigned long long) prev->tsc, prev->seq);
    667 			log_info("\t CPU%3u: TSC=%llu, SEQ=%u\n", this->cpu, (unsigned long long) this->tsc, this->seq);
    668 			failed++;
    669 		}
    670 
    671 		prev = this;
    672 	}
    673 
    674 	if (debug) {
    675 		if (failed)
    676 			log_info("cs: Failed: %lu\n", failed);
    677 		else
    678 			log_info("cs: Pass!\n");
    679 	}
    680 err:
    681 	free(entries);
    682 	return !!failed;
    683 }
    684 
    685 #else /* defined(FIO_HAVE_CPU_AFFINITY) && defined(ARCH_HAVE_CPU_CLOCK) */
    686 
    687 int fio_monotonic_clocktest(int debug)
    688 {
    689 	if (debug)
    690 		log_info("cs: current platform does not support CPU clocks\n");
    691 	return 1;
    692 }
    693 
    694 #endif
    695