gettime: use pthread_{set,get}specific() for TLS
[fio.git] / gettime.c
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