Branch data Line data Source code
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:
29 : : * # echo [1|0] >/proc/timer_stats
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;
71 : : unsigned int timer_flag;
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_RAW_SPINLOCK(table_lock);
85 : :
86 : : /*
87 : : * Per-CPU lookup locks for fast hash lookup:
88 : : */
89 : : static DEFINE_PER_CPU(raw_spinlock_t, tstats_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 : : int __read_mostly timer_stats_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 : :
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 : :
138 : 0 : static void reset_entries(void)
139 : : {
140 : 0 : nr_entries = 0;
141 : 0 : memset(entries, 0, sizeof(entries));
142 : 0 : memset(tstat_hash_table, 0, sizeof(tstat_hash_table));
143 : 0 : atomic_set(&overflow_count, 0);
144 : 0 : }
145 : :
146 : : static struct entry *alloc_entry(void)
147 : : {
148 [ # # ]: 0 : if (nr_entries >= MAX_ENTRIES)
149 : : return NULL;
150 : :
151 : 0 : return entries + nr_entries++;
152 : : }
153 : :
154 : : static int match_entries(struct entry *entry1, struct entry *entry2)
155 : : {
156 [ # # ][ # # ]: 0 : return entry1->timer == entry2->timer &&
157 [ # # ][ # # ]: 0 : entry1->start_func == entry2->start_func &&
158 [ # # ][ # # ]: 0 : entry1->expire_func == entry2->expire_func &&
[ # # ][ # # ]
159 : 0 : 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 : 0 : static struct entry *tstat_lookup(struct entry *entry, char *comm)
168 : : {
169 : : struct entry **head, *curr, *prev;
170 : :
171 : 0 : head = tstat_hashentry(entry);
172 : 0 : 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 [ # # ]: 0 : while (curr) {
180 [ # # ]: 0 : if (match_entries(curr, entry))
181 : : return curr;
182 : :
183 : 0 : 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 : 0 : raw_spin_lock(&table_lock);
192 : : /*
193 : : * Make sure we have not raced with another CPU:
194 : : */
195 [ # # ]: 0 : while (curr) {
196 [ # # ]: 0 : if (match_entries(curr, entry))
197 : : goto out_unlock;
198 : :
199 : : prev = curr;
200 : 0 : curr = curr->next;
201 : : }
202 : :
203 : : curr = alloc_entry();
204 [ # # ]: 0 : if (curr) {
205 : 0 : *curr = *entry;
206 : 0 : curr->count = 0;
207 : 0 : curr->next = NULL;
208 : 0 : memcpy(curr->comm, comm, TASK_COMM_LEN);
209 : :
210 : 0 : smp_mb(); /* Ensure that curr is initialized before insert */
211 : :
212 [ # # ]: 0 : if (prev)
213 : 0 : prev->next = curr;
214 : : else
215 : 0 : *head = curr;
216 : : }
217 : : out_unlock:
218 : : raw_spin_unlock(&table_lock);
219 : :
220 : 0 : 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 : 0 : void timer_stats_update_stats(void *timer, pid_t pid, void *startf,
235 : : void *timerf, char *comm,
236 : : unsigned int timer_flag)
237 : : {
238 : : /*
239 : : * It doesn't matter which lock we take:
240 : : */
241 : : raw_spinlock_t *lock;
242 : : struct entry *entry, input;
243 : : unsigned long flags;
244 : :
245 [ # # ]: 0 : if (likely(!timer_stats_active))
246 : 0 : return;
247 : :
248 : 0 : lock = &per_cpu(tstats_lookup_lock, raw_smp_processor_id());
249 : :
250 : 0 : input.timer = timer;
251 : 0 : input.start_func = startf;
252 : 0 : input.expire_func = timerf;
253 : 0 : input.pid = pid;
254 : 0 : input.timer_flag = timer_flag;
255 : :
256 : 0 : raw_spin_lock_irqsave(lock, flags);
257 [ # # ]: 0 : if (!timer_stats_active)
258 : : goto out_unlock;
259 : :
260 : 0 : entry = tstat_lookup(&input, comm);
261 [ # # ]: 0 : if (likely(entry))
262 : 0 : entry->count++;
263 : : else
264 : : atomic_inc(&overflow_count);
265 : :
266 : : out_unlock:
267 : 0 : raw_spin_unlock_irqrestore(lock, flags);
268 : : }
269 : :
270 : 0 : static void print_name_offset(struct seq_file *m, unsigned long addr)
271 : : {
272 : : char symname[KSYM_NAME_LEN];
273 : :
274 [ # # ]: 0 : if (lookup_symbol_name(addr, symname) < 0)
275 : 0 : seq_printf(m, "<%p>", (void *)addr);
276 : : else
277 : 0 : seq_printf(m, "%s", symname);
278 : 0 : }
279 : :
280 : 0 : 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 : 1 : mutex_lock(&show_mutex);
290 : : /*
291 : : * If still active then calculate up to now:
292 : : */
293 [ - + ]: 1 : if (timer_stats_active)
294 : 0 : time_stop = ktime_get();
295 : :
296 : 1 : time = ktime_sub(time_stop, time_start);
297 : :
298 : 1 : period = ktime_to_timespec(time);
299 : 1 : ms = period.tv_nsec / 1000000;
300 : :
301 : 1 : seq_puts(m, "Timer Stats Version: v0.3\n");
302 : 1 : seq_printf(m, "Sample period: %ld.%03ld s\n", period.tv_sec, ms);
303 [ - + ]: 1 : if (atomic_read(&overflow_count))
304 : 0 : seq_printf(m, "Overflow: %d entries\n", atomic_read(&overflow_count));
305 [ + - ]: 1 : seq_printf(m, "Collection: %s\n", timer_stats_active ? "active" : "inactive");
306 : :
307 [ - + ]: 1 : for (i = 0; i < nr_entries; i++) {
308 : 0 : entry = entries + i;
309 [ # # ]: 0 : if (entry->timer_flag & TIMER_STATS_FLAG_DEFERRABLE) {
310 : 0 : seq_printf(m, "%4luD, %5d %-16s ",
311 : 0 : entry->count, entry->pid, entry->comm);
312 : : } else {
313 : 0 : seq_printf(m, " %4lu, %5d %-16s ",
314 : 0 : entry->count, entry->pid, entry->comm);
315 : : }
316 : :
317 : 0 : print_name_offset(m, (unsigned long)entry->start_func);
318 : 0 : seq_puts(m, " (");
319 : 0 : print_name_offset(m, (unsigned long)entry->expire_func);
320 : 0 : seq_puts(m, ")\n");
321 : :
322 : 0 : events += entry->count;
323 : : }
324 : :
325 : 1 : ms += period.tv_sec * 1000;
326 [ + - ]: 1 : if (!ms)
327 : : ms = 1;
328 : :
329 [ - + ][ # # ]: 1 : if (events && period.tv_sec)
330 : 0 : seq_printf(m, "%ld total events, %ld.%03ld events/sec\n",
331 : 0 : events, events * 1000 / ms,
332 : 0 : (events * 1000000 / ms) % 1000);
333 : : else
334 : 1 : seq_printf(m, "%ld total events\n", events);
335 : :
336 : 1 : mutex_unlock(&show_mutex);
337 : :
338 : 1 : return 0;
339 : : }
340 : :
341 : : /*
342 : : * After a state change, make sure all concurrent lookup/update
343 : : * activities have stopped:
344 : : */
345 : 0 : static void sync_access(void)
346 : : {
347 : : unsigned long flags;
348 : : int cpu;
349 : :
350 [ # # ]: 0 : for_each_online_cpu(cpu) {
351 : 0 : raw_spinlock_t *lock = &per_cpu(tstats_lookup_lock, cpu);
352 : :
353 : 0 : raw_spin_lock_irqsave(lock, flags);
354 : : /* nothing */
355 : 0 : raw_spin_unlock_irqrestore(lock, flags);
356 : : }
357 : 0 : }
358 : :
359 : 0 : 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 [ # # ][ # # ]: 0 : if (count != 2 || *offs)
365 : : return -EINVAL;
366 : :
367 [ # # ]: 0 : if (copy_from_user(ctl, buf, count))
368 : : return -EFAULT;
369 : :
370 : 0 : mutex_lock(&show_mutex);
371 [ # # # ]: 0 : switch (ctl[0]) {
372 : : case '0':
373 [ # # ]: 0 : if (timer_stats_active) {
374 : 0 : timer_stats_active = 0;
375 : 0 : time_stop = ktime_get();
376 : 0 : sync_access();
377 : : }
378 : : break;
379 : : case '1':
380 [ # # ]: 0 : if (!timer_stats_active) {
381 : 0 : reset_entries();
382 : 0 : time_start = ktime_get();
383 : 0 : smp_mb();
384 : 0 : timer_stats_active = 1;
385 : : }
386 : : break;
387 : : default:
388 : : count = -EINVAL;
389 : : }
390 : 0 : mutex_unlock(&show_mutex);
391 : :
392 : 0 : return count;
393 : : }
394 : :
395 : 0 : static int tstats_open(struct inode *inode, struct file *filp)
396 : : {
397 : 1 : return single_open(filp, tstats_show, NULL);
398 : : }
399 : :
400 : : static const struct file_operations tstats_fops = {
401 : : .open = tstats_open,
402 : : .read = seq_read,
403 : : .write = tstats_write,
404 : : .llseek = seq_lseek,
405 : : .release = single_release,
406 : : };
407 : :
408 : 0 : void __init init_timer_stats(void)
409 : : {
410 : : int cpu;
411 : :
412 [ # # ]: 0 : for_each_possible_cpu(cpu)
413 : 0 : raw_spin_lock_init(&per_cpu(tstats_lookup_lock, cpu));
414 : 0 : }
415 : :
416 : 0 : static int __init init_tstats_procfs(void)
417 : : {
418 : : struct proc_dir_entry *pe;
419 : :
420 : : pe = proc_create("timer_stats", 0644, NULL, &tstats_fops);
421 [ # # ]: 0 : if (!pe)
422 : : return -ENOMEM;
423 : 0 : return 0;
424 : : }
425 : : __initcall(init_tstats_procfs);
|
