Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 1 | /* |
| 2 | * kernel/time/timer_stats.c |
| 3 | * |
| 4 | * Collect timer usage statistics. |
| 5 | * |
| 6 | * Copyright(C) 2006, Red Hat, Inc., Ingo Molnar |
| 7 | * Copyright(C) 2006 Timesys Corp., Thomas Gleixner <tglx@timesys.com> |
| 8 | * |
| 9 | * timer_stats is based on timer_top, a similar functionality which was part of |
| 10 | * Con Kolivas dyntick patch set. It was developed by Daniel Petrini at the |
| 11 | * Instituto Nokia de Tecnologia - INdT - Manaus. timer_top's design was based |
| 12 | * on dynamic allocation of the statistics entries and linear search based |
| 13 | * lookup combined with a global lock, rather than the static array, hash |
| 14 | * and per-CPU locking which is used by timer_stats. It was written for the |
| 15 | * pre hrtimer kernel code and therefore did not take hrtimers into account. |
| 16 | * Nevertheless it provided the base for the timer_stats implementation and |
| 17 | * was a helpful source of inspiration. Kudos to Daniel and the Nokia folks |
| 18 | * for this effort. |
| 19 | * |
| 20 | * timer_top.c is |
| 21 | * Copyright (C) 2005 Instituto Nokia de Tecnologia - INdT - Manaus |
| 22 | * Written by Daniel Petrini <d.pensator@gmail.com> |
| 23 | * timer_top.c was released under the GNU General Public License version 2 |
| 24 | * |
| 25 | * We export the addresses and counting of timer functions being called, |
| 26 | * the pid and cmdline from the owner process if applicable. |
| 27 | * |
| 28 | * Start/stop data collection: |
Pavel Machek | b10db7f | 2008-01-30 13:30:00 +0100 | [diff] [blame] | 29 | * # echo [1|0] >/proc/timer_stats |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 30 | * |
| 31 | * Display the information collected so far: |
| 32 | * # cat /proc/timer_stats |
| 33 | * |
| 34 | * This program is free software; you can redistribute it and/or modify |
| 35 | * it under the terms of the GNU General Public License version 2 as |
| 36 | * published by the Free Software Foundation. |
| 37 | */ |
| 38 | |
| 39 | #include <linux/proc_fs.h> |
| 40 | #include <linux/module.h> |
| 41 | #include <linux/spinlock.h> |
| 42 | #include <linux/sched.h> |
| 43 | #include <linux/seq_file.h> |
| 44 | #include <linux/kallsyms.h> |
| 45 | |
| 46 | #include <asm/uaccess.h> |
| 47 | |
| 48 | /* |
| 49 | * This is our basic unit of interest: a timer expiry event identified |
| 50 | * by the timer, its start/expire functions and the PID of the task that |
| 51 | * started the timer. We count the number of times an event happens: |
| 52 | */ |
| 53 | struct entry { |
| 54 | /* |
| 55 | * Hash list: |
| 56 | */ |
| 57 | struct entry *next; |
| 58 | |
| 59 | /* |
| 60 | * Hash keys: |
| 61 | */ |
| 62 | void *timer; |
| 63 | void *start_func; |
| 64 | void *expire_func; |
| 65 | pid_t pid; |
| 66 | |
| 67 | /* |
| 68 | * Number of timeout events: |
| 69 | */ |
| 70 | unsigned long count; |
Venki Pallipadi | c5c061b8 | 2007-07-15 23:40:30 -0700 | [diff] [blame] | 71 | unsigned int timer_flag; |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 72 | |
| 73 | /* |
| 74 | * We save the command-line string to preserve |
| 75 | * this information past task exit: |
| 76 | */ |
| 77 | char comm[TASK_COMM_LEN + 1]; |
| 78 | |
| 79 | } ____cacheline_aligned_in_smp; |
| 80 | |
| 81 | /* |
| 82 | * Spinlock protecting the tables - not taken during lookup: |
| 83 | */ |
| 84 | static DEFINE_SPINLOCK(table_lock); |
| 85 | |
| 86 | /* |
| 87 | * Per-CPU lookup locks for fast hash lookup: |
| 88 | */ |
| 89 | static DEFINE_PER_CPU(spinlock_t, lookup_lock); |
| 90 | |
| 91 | /* |
| 92 | * Mutex to serialize state changes with show-stats activities: |
| 93 | */ |
| 94 | static DEFINE_MUTEX(show_mutex); |
| 95 | |
| 96 | /* |
| 97 | * Collection status, active/inactive: |
| 98 | */ |
| 99 | static int __read_mostly active; |
| 100 | |
| 101 | /* |
| 102 | * Beginning/end timestamps of measurement: |
| 103 | */ |
| 104 | static ktime_t time_start, time_stop; |
| 105 | |
| 106 | /* |
| 107 | * tstat entry structs only get allocated while collection is |
| 108 | * active and never freed during that time - this simplifies |
| 109 | * things quite a bit. |
| 110 | * |
| 111 | * They get freed when a new collection period is started. |
| 112 | */ |
| 113 | #define MAX_ENTRIES_BITS 10 |
| 114 | #define MAX_ENTRIES (1UL << MAX_ENTRIES_BITS) |
| 115 | |
| 116 | static unsigned long nr_entries; |
| 117 | static struct entry entries[MAX_ENTRIES]; |
| 118 | |
| 119 | static atomic_t overflow_count; |
| 120 | |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 121 | /* |
| 122 | * The entries are in a hash-table, for fast lookup: |
| 123 | */ |
| 124 | #define TSTAT_HASH_BITS (MAX_ENTRIES_BITS - 1) |
| 125 | #define TSTAT_HASH_SIZE (1UL << TSTAT_HASH_BITS) |
| 126 | #define TSTAT_HASH_MASK (TSTAT_HASH_SIZE - 1) |
| 127 | |
| 128 | #define __tstat_hashfn(entry) \ |
| 129 | (((unsigned long)(entry)->timer ^ \ |
| 130 | (unsigned long)(entry)->start_func ^ \ |
| 131 | (unsigned long)(entry)->expire_func ^ \ |
| 132 | (unsigned long)(entry)->pid ) & TSTAT_HASH_MASK) |
| 133 | |
| 134 | #define tstat_hashentry(entry) (tstat_hash_table + __tstat_hashfn(entry)) |
| 135 | |
| 136 | static struct entry *tstat_hash_table[TSTAT_HASH_SIZE] __read_mostly; |
| 137 | |
Bjorn Steinbrink | 9fcc15e | 2007-06-01 00:47:15 -0700 | [diff] [blame] | 138 | static void reset_entries(void) |
| 139 | { |
| 140 | nr_entries = 0; |
| 141 | memset(entries, 0, sizeof(entries)); |
| 142 | memset(tstat_hash_table, 0, sizeof(tstat_hash_table)); |
| 143 | atomic_set(&overflow_count, 0); |
| 144 | } |
| 145 | |
| 146 | static struct entry *alloc_entry(void) |
| 147 | { |
| 148 | if (nr_entries >= MAX_ENTRIES) |
| 149 | return NULL; |
| 150 | |
| 151 | return entries + nr_entries++; |
| 152 | } |
| 153 | |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 154 | static int match_entries(struct entry *entry1, struct entry *entry2) |
| 155 | { |
| 156 | return entry1->timer == entry2->timer && |
| 157 | entry1->start_func == entry2->start_func && |
| 158 | entry1->expire_func == entry2->expire_func && |
| 159 | entry1->pid == entry2->pid; |
| 160 | } |
| 161 | |
| 162 | /* |
| 163 | * Look up whether an entry matching this item is present |
| 164 | * in the hash already. Must be called with irqs off and the |
| 165 | * lookup lock held: |
| 166 | */ |
| 167 | static struct entry *tstat_lookup(struct entry *entry, char *comm) |
| 168 | { |
| 169 | struct entry **head, *curr, *prev; |
| 170 | |
| 171 | head = tstat_hashentry(entry); |
| 172 | curr = *head; |
| 173 | |
| 174 | /* |
| 175 | * The fastpath is when the entry is already hashed, |
| 176 | * we do this with the lookup lock held, but with the |
| 177 | * table lock not held: |
| 178 | */ |
| 179 | while (curr) { |
| 180 | if (match_entries(curr, entry)) |
| 181 | return curr; |
| 182 | |
| 183 | curr = curr->next; |
| 184 | } |
| 185 | /* |
| 186 | * Slowpath: allocate, set up and link a new hash entry: |
| 187 | */ |
| 188 | prev = NULL; |
| 189 | curr = *head; |
| 190 | |
| 191 | spin_lock(&table_lock); |
| 192 | /* |
| 193 | * Make sure we have not raced with another CPU: |
| 194 | */ |
| 195 | while (curr) { |
| 196 | if (match_entries(curr, entry)) |
| 197 | goto out_unlock; |
| 198 | |
| 199 | prev = curr; |
| 200 | curr = curr->next; |
| 201 | } |
| 202 | |
| 203 | curr = alloc_entry(); |
| 204 | if (curr) { |
| 205 | *curr = *entry; |
| 206 | curr->count = 0; |
Bjorn Steinbrink | 9fcc15e | 2007-06-01 00:47:15 -0700 | [diff] [blame] | 207 | curr->next = NULL; |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 208 | memcpy(curr->comm, comm, TASK_COMM_LEN); |
Bjorn Steinbrink | 9fcc15e | 2007-06-01 00:47:15 -0700 | [diff] [blame] | 209 | |
| 210 | smp_mb(); /* Ensure that curr is initialized before insert */ |
| 211 | |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 212 | if (prev) |
| 213 | prev->next = curr; |
| 214 | else |
| 215 | *head = curr; |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 216 | } |
| 217 | out_unlock: |
| 218 | spin_unlock(&table_lock); |
| 219 | |
| 220 | return curr; |
| 221 | } |
| 222 | |
| 223 | /** |
| 224 | * timer_stats_update_stats - Update the statistics for a timer. |
| 225 | * @timer: pointer to either a timer_list or a hrtimer |
| 226 | * @pid: the pid of the task which set up the timer |
| 227 | * @startf: pointer to the function which did the timer setup |
| 228 | * @timerf: pointer to the timer callback function of the timer |
| 229 | * @comm: name of the process which set up the timer |
| 230 | * |
| 231 | * When the timer is already registered, then the event counter is |
| 232 | * incremented. Otherwise the timer is registered in a free slot. |
| 233 | */ |
| 234 | void timer_stats_update_stats(void *timer, pid_t pid, void *startf, |
Venki Pallipadi | c5c061b8 | 2007-07-15 23:40:30 -0700 | [diff] [blame] | 235 | void *timerf, char *comm, |
| 236 | unsigned int timer_flag) |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 237 | { |
| 238 | /* |
| 239 | * It doesnt matter which lock we take: |
| 240 | */ |
Ingo Molnar | c1a834d | 2007-06-01 00:47:16 -0700 | [diff] [blame] | 241 | spinlock_t *lock; |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 242 | struct entry *entry, input; |
| 243 | unsigned long flags; |
| 244 | |
Ingo Molnar | c1a834d | 2007-06-01 00:47:16 -0700 | [diff] [blame] | 245 | if (likely(!active)) |
| 246 | return; |
| 247 | |
| 248 | lock = &per_cpu(lookup_lock, raw_smp_processor_id()); |
| 249 | |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 250 | input.timer = timer; |
| 251 | input.start_func = startf; |
| 252 | input.expire_func = timerf; |
| 253 | input.pid = pid; |
Venki Pallipadi | c5c061b8 | 2007-07-15 23:40:30 -0700 | [diff] [blame] | 254 | input.timer_flag = timer_flag; |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 255 | |
| 256 | spin_lock_irqsave(lock, flags); |
| 257 | if (!active) |
| 258 | goto out_unlock; |
| 259 | |
| 260 | entry = tstat_lookup(&input, comm); |
| 261 | if (likely(entry)) |
| 262 | entry->count++; |
| 263 | else |
| 264 | atomic_inc(&overflow_count); |
| 265 | |
| 266 | out_unlock: |
| 267 | spin_unlock_irqrestore(lock, flags); |
| 268 | } |
| 269 | |
| 270 | static void print_name_offset(struct seq_file *m, unsigned long addr) |
| 271 | { |
Tejun Heo | 9281ace | 2007-07-17 04:03:51 -0700 | [diff] [blame] | 272 | char symname[KSYM_NAME_LEN]; |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 273 | |
Alexey Dobriyan | 9d65cb4 | 2007-05-08 00:28:43 -0700 | [diff] [blame] | 274 | if (lookup_symbol_name(addr, symname) < 0) |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 275 | seq_printf(m, "<%p>", (void *)addr); |
Alexey Dobriyan | 9d65cb4 | 2007-05-08 00:28:43 -0700 | [diff] [blame] | 276 | else |
| 277 | seq_printf(m, "%s", symname); |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 278 | } |
| 279 | |
| 280 | static int tstats_show(struct seq_file *m, void *v) |
| 281 | { |
| 282 | struct timespec period; |
| 283 | struct entry *entry; |
| 284 | unsigned long ms; |
| 285 | long events = 0; |
| 286 | ktime_t time; |
| 287 | int i; |
| 288 | |
| 289 | mutex_lock(&show_mutex); |
| 290 | /* |
| 291 | * If still active then calculate up to now: |
| 292 | */ |
| 293 | if (active) |
| 294 | time_stop = ktime_get(); |
| 295 | |
| 296 | time = ktime_sub(time_stop, time_start); |
| 297 | |
| 298 | period = ktime_to_timespec(time); |
| 299 | ms = period.tv_nsec / 1000000; |
| 300 | |
Venki Pallipadi | c5c061b8 | 2007-07-15 23:40:30 -0700 | [diff] [blame] | 301 | seq_puts(m, "Timer Stats Version: v0.2\n"); |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 302 | seq_printf(m, "Sample period: %ld.%03ld s\n", period.tv_sec, ms); |
| 303 | if (atomic_read(&overflow_count)) |
| 304 | seq_printf(m, "Overflow: %d entries\n", |
| 305 | atomic_read(&overflow_count)); |
| 306 | |
| 307 | for (i = 0; i < nr_entries; i++) { |
| 308 | entry = entries + i; |
Venki Pallipadi | c5c061b8 | 2007-07-15 23:40:30 -0700 | [diff] [blame] | 309 | if (entry->timer_flag & TIMER_STATS_FLAG_DEFERRABLE) { |
| 310 | seq_printf(m, "%4luD, %5d %-16s ", |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 311 | entry->count, entry->pid, entry->comm); |
Venki Pallipadi | c5c061b8 | 2007-07-15 23:40:30 -0700 | [diff] [blame] | 312 | } else { |
| 313 | seq_printf(m, " %4lu, %5d %-16s ", |
| 314 | entry->count, entry->pid, entry->comm); |
| 315 | } |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 316 | |
| 317 | print_name_offset(m, (unsigned long)entry->start_func); |
| 318 | seq_puts(m, " ("); |
| 319 | print_name_offset(m, (unsigned long)entry->expire_func); |
| 320 | seq_puts(m, ")\n"); |
| 321 | |
| 322 | events += entry->count; |
| 323 | } |
| 324 | |
| 325 | ms += period.tv_sec * 1000; |
| 326 | if (!ms) |
| 327 | ms = 1; |
| 328 | |
| 329 | if (events && period.tv_sec) |
Anton Blanchard | 74922be14 | 2007-10-07 00:24:31 -0700 | [diff] [blame] | 330 | seq_printf(m, "%ld total events, %ld.%03ld events/sec\n", |
| 331 | events, events * 1000 / ms, |
| 332 | (events * 1000000 / ms) % 1000); |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 333 | else |
| 334 | seq_printf(m, "%ld total events\n", events); |
| 335 | |
| 336 | mutex_unlock(&show_mutex); |
| 337 | |
| 338 | return 0; |
| 339 | } |
| 340 | |
| 341 | /* |
| 342 | * After a state change, make sure all concurrent lookup/update |
| 343 | * activities have stopped: |
| 344 | */ |
| 345 | static void sync_access(void) |
| 346 | { |
| 347 | unsigned long flags; |
| 348 | int cpu; |
| 349 | |
| 350 | for_each_online_cpu(cpu) { |
| 351 | spin_lock_irqsave(&per_cpu(lookup_lock, cpu), flags); |
| 352 | /* nothing */ |
| 353 | spin_unlock_irqrestore(&per_cpu(lookup_lock, cpu), flags); |
| 354 | } |
| 355 | } |
| 356 | |
| 357 | static ssize_t tstats_write(struct file *file, const char __user *buf, |
| 358 | size_t count, loff_t *offs) |
| 359 | { |
| 360 | char ctl[2]; |
| 361 | |
| 362 | if (count != 2 || *offs) |
| 363 | return -EINVAL; |
| 364 | |
| 365 | if (copy_from_user(ctl, buf, count)) |
| 366 | return -EFAULT; |
| 367 | |
| 368 | mutex_lock(&show_mutex); |
| 369 | switch (ctl[0]) { |
| 370 | case '0': |
| 371 | if (active) { |
| 372 | active = 0; |
| 373 | time_stop = ktime_get(); |
| 374 | sync_access(); |
| 375 | } |
| 376 | break; |
| 377 | case '1': |
| 378 | if (!active) { |
| 379 | reset_entries(); |
| 380 | time_start = ktime_get(); |
Bjorn Steinbrink | 9fcc15e | 2007-06-01 00:47:15 -0700 | [diff] [blame] | 381 | smp_mb(); |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 382 | active = 1; |
| 383 | } |
| 384 | break; |
| 385 | default: |
| 386 | count = -EINVAL; |
| 387 | } |
| 388 | mutex_unlock(&show_mutex); |
| 389 | |
| 390 | return count; |
| 391 | } |
| 392 | |
| 393 | static int tstats_open(struct inode *inode, struct file *filp) |
| 394 | { |
| 395 | return single_open(filp, tstats_show, NULL); |
| 396 | } |
| 397 | |
| 398 | static struct file_operations tstats_fops = { |
| 399 | .open = tstats_open, |
| 400 | .read = seq_read, |
| 401 | .write = tstats_write, |
| 402 | .llseek = seq_lseek, |
Alexey Dobriyan | 5ea473a | 2007-07-31 00:38:50 -0700 | [diff] [blame] | 403 | .release = single_release, |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 404 | }; |
| 405 | |
| 406 | void __init init_timer_stats(void) |
| 407 | { |
| 408 | int cpu; |
| 409 | |
| 410 | for_each_possible_cpu(cpu) |
| 411 | spin_lock_init(&per_cpu(lookup_lock, cpu)); |
| 412 | } |
| 413 | |
| 414 | static int __init init_tstats_procfs(void) |
| 415 | { |
| 416 | struct proc_dir_entry *pe; |
| 417 | |
Denis V. Lunev | c33fff0 | 2008-04-29 01:02:31 -0700 | [diff] [blame] | 418 | pe = proc_create("timer_stats", 0644, NULL, &tstats_fops); |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 419 | if (!pe) |
| 420 | return -ENOMEM; |
Ingo Molnar | 82f67cd | 2007-02-16 01:28:13 -0800 | [diff] [blame] | 421 | return 0; |
| 422 | } |
| 423 | __initcall(init_tstats_procfs); |