Commit | Line | Data |
---|---|---|
82f67cd9 IM |
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: | |
b10db7f0 | 29 | * # echo [1|0] >/proc/timer_stats |
82f67cd9 IM |
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; | |
c5c061b8 | 71 | unsigned int timer_flag; |
82f67cd9 IM |
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 | */ | |
2737c49f | 84 | static DEFINE_RAW_SPINLOCK(table_lock); |
82f67cd9 IM |
85 | |
86 | /* | |
87 | * Per-CPU lookup locks for fast hash lookup: | |
88 | */ | |
ecb49d1a | 89 | static DEFINE_PER_CPU(raw_spinlock_t, tstats_lookup_lock); |
82f67cd9 IM |
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 | */ | |
507e1231 | 99 | int __read_mostly timer_stats_active; |
82f67cd9 IM |
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 | ||
82f67cd9 IM |
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 | ||
9fcc15ec BS |
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 | ||
82f67cd9 IM |
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 | ||
2737c49f | 191 | raw_spin_lock(&table_lock); |
82f67cd9 IM |
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; | |
9fcc15ec | 207 | curr->next = NULL; |
82f67cd9 | 208 | memcpy(curr->comm, comm, TASK_COMM_LEN); |
9fcc15ec BS |
209 | |
210 | smp_mb(); /* Ensure that curr is initialized before insert */ | |
211 | ||
82f67cd9 IM |
212 | if (prev) |
213 | prev->next = curr; | |
214 | else | |
215 | *head = curr; | |
82f67cd9 IM |
216 | } |
217 | out_unlock: | |
2737c49f | 218 | raw_spin_unlock(&table_lock); |
82f67cd9 IM |
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, | |
c5c061b8 VP |
235 | void *timerf, char *comm, |
236 | unsigned int timer_flag) | |
82f67cd9 IM |
237 | { |
238 | /* | |
25985edc | 239 | * It doesn't matter which lock we take: |
82f67cd9 | 240 | */ |
ecb49d1a | 241 | raw_spinlock_t *lock; |
82f67cd9 IM |
242 | struct entry *entry, input; |
243 | unsigned long flags; | |
244 | ||
507e1231 | 245 | if (likely(!timer_stats_active)) |
c1a834dc IM |
246 | return; |
247 | ||
1871e52c | 248 | lock = &per_cpu(tstats_lookup_lock, raw_smp_processor_id()); |
c1a834dc | 249 | |
82f67cd9 IM |
250 | input.timer = timer; |
251 | input.start_func = startf; | |
252 | input.expire_func = timerf; | |
253 | input.pid = pid; | |
c5c061b8 | 254 | input.timer_flag = timer_flag; |
82f67cd9 | 255 | |
ecb49d1a | 256 | raw_spin_lock_irqsave(lock, flags); |
507e1231 | 257 | if (!timer_stats_active) |
82f67cd9 IM |
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: | |
ecb49d1a | 267 | raw_spin_unlock_irqrestore(lock, flags); |
82f67cd9 IM |
268 | } |
269 | ||
270 | static void print_name_offset(struct seq_file *m, unsigned long addr) | |
271 | { | |
9281acea | 272 | char symname[KSYM_NAME_LEN]; |
82f67cd9 | 273 | |
9d65cb4a | 274 | if (lookup_symbol_name(addr, symname) < 0) |
82f67cd9 | 275 | seq_printf(m, "<%p>", (void *)addr); |
9d65cb4a AD |
276 | else |
277 | seq_printf(m, "%s", symname); | |
82f67cd9 IM |
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 | */ | |
507e1231 | 293 | if (timer_stats_active) |
82f67cd9 IM |
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 | ||
c5c061b8 | 301 | seq_puts(m, "Timer Stats Version: v0.2\n"); |
82f67cd9 IM |
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; | |
c5c061b8 VP |
309 | if (entry->timer_flag & TIMER_STATS_FLAG_DEFERRABLE) { |
310 | seq_printf(m, "%4luD, %5d %-16s ", | |
82f67cd9 | 311 | entry->count, entry->pid, entry->comm); |
c5c061b8 VP |
312 | } else { |
313 | seq_printf(m, " %4lu, %5d %-16s ", | |
314 | entry->count, entry->pid, entry->comm); | |
315 | } | |
82f67cd9 IM |
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) | |
74922be1 AB |
330 | seq_printf(m, "%ld total events, %ld.%03ld events/sec\n", |
331 | events, events * 1000 / ms, | |
332 | (events * 1000000 / ms) % 1000); | |
82f67cd9 IM |
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) { | |
ecb49d1a TG |
351 | raw_spinlock_t *lock = &per_cpu(tstats_lookup_lock, cpu); |
352 | ||
353 | raw_spin_lock_irqsave(lock, flags); | |
82f67cd9 | 354 | /* nothing */ |
ecb49d1a | 355 | raw_spin_unlock_irqrestore(lock, flags); |
82f67cd9 IM |
356 | } |
357 | } | |
358 | ||
359 | static ssize_t tstats_write(struct file *file, const char __user *buf, | |
360 | size_t count, loff_t *offs) | |
361 | { | |
362 | char ctl[2]; | |
363 | ||
364 | if (count != 2 || *offs) | |
365 | return -EINVAL; | |
366 | ||
367 | if (copy_from_user(ctl, buf, count)) | |
368 | return -EFAULT; | |
369 | ||
370 | mutex_lock(&show_mutex); | |
371 | switch (ctl[0]) { | |
372 | case '0': | |
507e1231 HC |
373 | if (timer_stats_active) { |
374 | timer_stats_active = 0; | |
82f67cd9 IM |
375 | time_stop = ktime_get(); |
376 | sync_access(); | |
377 | } | |
378 | break; | |
379 | case '1': | |
507e1231 | 380 | if (!timer_stats_active) { |
82f67cd9 IM |
381 | reset_entries(); |
382 | time_start = ktime_get(); | |
9fcc15ec | 383 | smp_mb(); |
507e1231 | 384 | timer_stats_active = 1; |
82f67cd9 IM |
385 | } |
386 | break; | |
387 | default: | |
388 | count = -EINVAL; | |
389 | } | |
390 | mutex_unlock(&show_mutex); | |
391 | ||
392 | return count; | |
393 | } | |
394 | ||
395 | static int tstats_open(struct inode *inode, struct file *filp) | |
396 | { | |
397 | return single_open(filp, tstats_show, NULL); | |
398 | } | |
399 | ||
828c0950 | 400 | static const struct file_operations tstats_fops = { |
82f67cd9 IM |
401 | .open = tstats_open, |
402 | .read = seq_read, | |
403 | .write = tstats_write, | |
404 | .llseek = seq_lseek, | |
5ea473a1 | 405 | .release = single_release, |
82f67cd9 IM |
406 | }; |
407 | ||
408 | void __init init_timer_stats(void) | |
409 | { | |
410 | int cpu; | |
411 | ||
412 | for_each_possible_cpu(cpu) | |
ecb49d1a | 413 | raw_spin_lock_init(&per_cpu(tstats_lookup_lock, cpu)); |
82f67cd9 IM |
414 | } |
415 | ||
416 | static int __init init_tstats_procfs(void) | |
417 | { | |
418 | struct proc_dir_entry *pe; | |
419 | ||
c33fff0a | 420 | pe = proc_create("timer_stats", 0644, NULL, &tstats_fops); |
82f67cd9 IM |
421 | if (!pe) |
422 | return -ENOMEM; | |
82f67cd9 IM |
423 | return 0; |
424 | } | |
425 | __initcall(init_tstats_procfs); |