From e59494f441c834ca7aaa0e6fa6678ddbd3d72743 Mon Sep 17 00:00:00 2001 From: Steven Rostedt Date: Wed, 16 Jul 2008 00:13:45 -0400 Subject: ftrace: fix 4d3702b6 (post-v2.6.26): WARNING: at kernel/lockdep.c:2731 check_flags (ftrace) On Wed, 16 Jul 2008, Vegard Nossum wrote: > When booting 4d3702b6, I got this huge thing: > > Testing tracer wakeup: <4>------------[ cut here ]------------ > WARNING: at kernel/lockdep.c:2731 check_flags+0x123/0x160() > Modules linked in: > Pid: 1, comm: swapper Not tainted 2.6.26-crashing-02127-g4d3702b6 #30 > [] warn_on_slowpath+0x59/0xb0 > [] ? ftrace_call+0x5/0x8 > [] ? native_read_tsc+0x0/0x20 > [] ? sub_preempt_count+0x12/0xf0 > [] ? trace_hardirqs_off+0xb/0x10 > [] ? __lock_acquire+0x2cc/0x1120 > [] ? trace_hardirqs_off+0xb/0x10 > [] ? mcount_call+0x5/0xa > [] check_flags+0x123/0x160 > [] lock_acquire+0x51/0xd0 > [] ? ftrace_call+0x5/0x8 > [] _spin_lock_irqsave+0x5f/0xa0 > [] ? ftrace_record_ip+0xf5/0x220 > [] ? debug_locks_off+0x3/0x50 > [] ftrace_record_ip+0xf5/0x220 > [] mcount_call+0x5/0xa > [] ? debug_locks_off+0x8/0x50 > [] check_flags+0xf7/0x160 > [] lock_acquire+0x51/0xd0 > [] ? ftrace_call+0x5/0x8 > [] _spin_lock_irqsave+0x5f/0xa0 > [] ? wakeup_tracer_call+0x6d/0xf0 > [] ? _local_bh_enable+0x62/0xb0 > [] ? sub_preempt_count+0xd/0xf0 > [] wakeup_tracer_call+0x6d/0xf0 > [] ? __do_softirq+0xf4/0x110 > [] ? wakeup_tracer_call+0x91/0xf0 > [] ftrace_call+0x5/0x8 > [] ? __do_softirq+0xf4/0x110 > [] ? sub_preempt_count+0x12/0xf0 > [] _local_bh_enable+0x62/0xb0 > [] __do_softirq+0xf4/0x110 > [] do_softirq+0xad/0xb0 > [] irq_exit+0xa5/0xb0 > [] smp_apic_timer_interrupt+0x66/0xa0 > [] ? trace_hardirqs_off_thunk+0xc/0x10 > [] apic_timer_interrupt+0x2d/0x34 > [] ? find_usage_backwards+0xb/0xf0 > [] ? _spin_unlock_irqrestore+0x69/0x80 > [] tg_shares_up+0x132/0x1d0 > [] walk_tg_tree+0x62/0xa0 > [] ? tg_shares_up+0x0/0x1d0 > [] ? tg_nop+0x0/0x10 > [] update_shares+0x5d/0x80 > [] try_to_wake_up+0x6f/0x280 > [] ? __ftrace_modify_code+0x0/0xc0 > [] ? __ftrace_modify_code+0x0/0xc0 > [] wake_up_process+0x14/0x20 > [] kthread_create+0x66/0xb0 > [] ? do_stop+0x0/0x200 > [] ? __stop_machine_run+0x30/0xb0 > [] __stop_machine_run+0x50/0xb0 > [] ? do_stop+0x0/0x200 > [] ? __ftrace_modify_code+0x0/0xc0 > [] ? mutex_unlock+0xd/0x10 > [] stop_machine_run+0x2c/0x60 > [] unregister_ftrace_function+0x103/0x180 > [] stop_wakeup_tracer+0x17/0x60 > [] wakeup_tracer_ctrl_update+0xf/0x30 > [] trace_selftest_startup_wakeup+0xb5/0x130 > [] ? trace_wakeup_test_thread+0x0/0x70 > [] register_tracer+0x135/0x1b0 > [] init_wakeup_tracer+0xd/0xf > [] kernel_init+0x1a9/0x2ce > [] ? _spin_unlock_irq+0x3b/0x60 > [] ? trace_hardirqs_on_thunk+0xc/0x10 > [] ? init_wakeup_tracer+0x0/0xf > [] ? trace_hardirqs_on_caller+0x126/0x180 > [] ? trace_hardirqs_on_thunk+0xc/0x10 > [] ? restore_nocheck_notrace+0x0/0xe > [] ? kernel_init+0x0/0x2ce > [] ? kernel_init+0x0/0x2ce > [] kernel_thread_helper+0x7/0x10 > ======================= > ---[ end trace a7919e7f17c0a725 ]--- > irq event stamp: 579530 > hardirqs last enabled at (579528): [] trace_hardirqs_on+0xb/0x10 > hardirqs last disabled at (579529): [] trace_hardirqs_off+0xb/0x10 > softirqs last enabled at (579530): [] __do_softirq+0xf4/0x110 > softirqs last disabled at (579517): [] do_softirq+0xad/0xb0 > irq event stamp: 579530 > hardirqs last enabled at (579528): [] trace_hardirqs_on+0xb/0x10 > hardirqs last disabled at (579529): [] trace_hardirqs_off+0xb/0x10 > softirqs last enabled at (579530): [] __do_softirq+0xf4/0x110 > softirqs last disabled at (579517): [] do_softirq+0xad/0xb0 > PASSED > > Incidentally, the kernel also hung while I was typing in this report. Things get weird between lockdep and ftrace because ftrace can be called within lockdep internal code (via the mcount pointer) and lockdep can be called with ftrace (via spin_locks). Signed-off-by: Steven Rostedt Tested-by: Vegard Nossum Signed-off-by: Ingo Molnar --- kernel/trace/trace_sched_wakeup.c | 27 ++++++++++++++++----------- 1 file changed, 16 insertions(+), 11 deletions(-) (limited to 'kernel/trace') diff --git a/kernel/trace/trace_sched_wakeup.c b/kernel/trace/trace_sched_wakeup.c index 3c8d61df4474..e303ccb62cdf 100644 --- a/kernel/trace/trace_sched_wakeup.c +++ b/kernel/trace/trace_sched_wakeup.c @@ -26,7 +26,8 @@ static struct task_struct *wakeup_task; static int wakeup_cpu; static unsigned wakeup_prio = -1; -static DEFINE_SPINLOCK(wakeup_lock); +static raw_spinlock_t wakeup_lock = + (raw_spinlock_t)__RAW_SPIN_LOCK_UNLOCKED; static void __wakeup_reset(struct trace_array *tr); @@ -56,7 +57,8 @@ wakeup_tracer_call(unsigned long ip, unsigned long parent_ip) if (unlikely(disabled != 1)) goto out; - spin_lock_irqsave(&wakeup_lock, flags); + local_irq_save(flags); + __raw_spin_lock(&wakeup_lock); if (unlikely(!wakeup_task)) goto unlock; @@ -71,7 +73,8 @@ wakeup_tracer_call(unsigned long ip, unsigned long parent_ip) trace_function(tr, data, ip, parent_ip, flags); unlock: - spin_unlock_irqrestore(&wakeup_lock, flags); + __raw_spin_unlock(&wakeup_lock); + local_irq_restore(flags); out: atomic_dec(&data->disabled); @@ -145,7 +148,8 @@ wakeup_sched_switch(void *private, void *rq, struct task_struct *prev, if (likely(disabled != 1)) goto out; - spin_lock_irqsave(&wakeup_lock, flags); + local_irq_save(flags); + __raw_spin_lock(&wakeup_lock); /* We could race with grabbing wakeup_lock */ if (unlikely(!tracer_enabled || next != wakeup_task)) @@ -174,7 +178,8 @@ wakeup_sched_switch(void *private, void *rq, struct task_struct *prev, out_unlock: __wakeup_reset(tr); - spin_unlock_irqrestore(&wakeup_lock, flags); + __raw_spin_unlock(&wakeup_lock); + local_irq_restore(flags); out: atomic_dec(&tr->data[cpu]->disabled); } @@ -209,8 +214,6 @@ static void __wakeup_reset(struct trace_array *tr) struct trace_array_cpu *data; int cpu; - assert_spin_locked(&wakeup_lock); - for_each_possible_cpu(cpu) { data = tr->data[cpu]; tracing_reset(data); @@ -229,9 +232,11 @@ static void wakeup_reset(struct trace_array *tr) { unsigned long flags; - spin_lock_irqsave(&wakeup_lock, flags); + local_irq_save(flags); + __raw_spin_lock(&wakeup_lock); __wakeup_reset(tr); - spin_unlock_irqrestore(&wakeup_lock, flags); + __raw_spin_unlock(&wakeup_lock); + local_irq_restore(flags); } static void @@ -252,7 +257,7 @@ wakeup_check_start(struct trace_array *tr, struct task_struct *p, goto out; /* interrupts should be off from try_to_wake_up */ - spin_lock(&wakeup_lock); + __raw_spin_lock(&wakeup_lock); /* check for races. */ if (!tracer_enabled || p->prio >= wakeup_prio) @@ -274,7 +279,7 @@ wakeup_check_start(struct trace_array *tr, struct task_struct *p, CALLER_ADDR1, CALLER_ADDR2, flags); out_locked: - spin_unlock(&wakeup_lock); + __raw_spin_unlock(&wakeup_lock); out: atomic_dec(&tr->data[cpu]->disabled); } -- cgit v1.2.2 From 1e01cb0c6ff7e9ddb6547551794c6aa82785a7cb Mon Sep 17 00:00:00 2001 From: Steven Rostedt Date: Tue, 15 Jul 2008 09:53:37 -0400 Subject: ftrace: only trace preempt off with preempt tracer When PREEMPT_TRACER and IRQSOFF_TRACER are both configured and irqsoff tracer is running, the preempt_off sections might also be traced. Thanks to Andrew Morton for pointing out my mistake of spin_lock disabling interrupts while he was reviewing ftrace.txt. Seems that my example I used actually hit this bug. Signed-off-by: Steven Rostedt Cc: Linus Torvalds Cc: Andrew Morton Cc: Peter Zijlstra Signed-off-by: Ingo Molnar --- kernel/trace/trace_irqsoff.c | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) (limited to 'kernel/trace') diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c index 421d6fe3650e..b1e4a89b08eb 100644 --- a/kernel/trace/trace_irqsoff.c +++ b/kernel/trace/trace_irqsoff.c @@ -337,12 +337,14 @@ EXPORT_SYMBOL(trace_hardirqs_off_caller); #ifdef CONFIG_PREEMPT_TRACER void trace_preempt_on(unsigned long a0, unsigned long a1) { - stop_critical_timing(a0, a1); + if (preempt_trace()) + stop_critical_timing(a0, a1); } void trace_preempt_off(unsigned long a0, unsigned long a1) { - start_critical_timing(a0, a1); + if (preempt_trace()) + start_critical_timing(a0, a1); } #endif /* CONFIG_PREEMPT_TRACER */ -- cgit v1.2.2 From 65c011845316d3c1381f478ca0d8265c43b3b039 Mon Sep 17 00:00:00 2001 From: Mike Travis Date: Tue, 15 Jul 2008 14:14:30 -0700 Subject: cpumask: Replace cpumask_of_cpu with cpumask_of_cpu_ptr * This patch replaces the dangerous lvalue version of cpumask_of_cpu with new cpumask_of_cpu_ptr macros. These are patterned after the node_to_cpumask_ptr macros. In general terms, if there is a cpumask_of_cpu_map[] then a pointer to the cpumask_of_cpu_map[cpu] entry is used. The cpumask_of_cpu_map is provided when there is a large NR_CPUS count, reducing greatly the amount of code generated and stack space used for cpumask_of_cpu(). The pointer to the cpumask_t value is needed for calling set_cpus_allowed_ptr() to reduce the amount of stack space needed to pass the cpumask_t value. If there isn't a cpumask_of_cpu_map[], then a temporary variable is declared and filled in with value from cpumask_of_cpu(cpu) as well as a pointer variable pointing to this temporary variable. Afterwards, the pointer is used to reference the cpumask value. The compiler will optimize out the extra dereference through the pointer as well as the stack space used for the pointer, resulting in identical code. A good example of the orthogonal usages is in net/sunrpc/svc.c: case SVC_POOL_PERCPU: { unsigned int cpu = m->pool_to[pidx]; cpumask_of_cpu_ptr(cpumask, cpu); *oldmask = current->cpus_allowed; set_cpus_allowed_ptr(current, cpumask); return 1; } case SVC_POOL_PERNODE: { unsigned int node = m->pool_to[pidx]; node_to_cpumask_ptr(nodecpumask, node); *oldmask = current->cpus_allowed; set_cpus_allowed_ptr(current, nodecpumask); return 1; } Signed-off-by: Mike Travis Signed-off-by: Ingo Molnar --- kernel/trace/trace_sysprof.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) (limited to 'kernel/trace') diff --git a/kernel/trace/trace_sysprof.c b/kernel/trace/trace_sysprof.c index 2301e1e7c606..63528086337c 100644 --- a/kernel/trace/trace_sysprof.c +++ b/kernel/trace/trace_sysprof.c @@ -213,7 +213,9 @@ static void start_stack_timers(void) int cpu; for_each_online_cpu(cpu) { - set_cpus_allowed_ptr(current, &cpumask_of_cpu(cpu)); + cpumask_of_cpu_ptr(new_mask, cpu); + + set_cpus_allowed_ptr(current, new_mask); start_stack_timer(cpu); } set_cpus_allowed_ptr(current, &saved_mask); -- cgit v1.2.2 From 1986b0cb1671ea39178b4e2b00461109728fc935 Mon Sep 17 00:00:00 2001 From: Ingo Molnar Date: Thu, 24 Jul 2008 08:10:02 +0200 Subject: ftrace: remove latency-tracer leftover remove the :vim=ft=help tag from trace files. I used them years ago to syntax-highlight traces and forgot about this hack. Signed-off-by: Ingo Molnar --- kernel/trace/trace.c | 3 --- 1 file changed, 3 deletions(-) (limited to 'kernel/trace') diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index 868e121c8e38..fc20e09a6cb1 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -1203,9 +1203,6 @@ static void *s_next(struct seq_file *m, void *v, loff_t *pos) iter->pos = *pos; - if (last_ent && !ent) - seq_puts(m, "\n\nvim:ft=help\n"); - return ent; } -- cgit v1.2.2 From a89cc1959d0ea5f36bf7421dc97b34f03809637d Mon Sep 17 00:00:00 2001 From: Harvey Harrison Date: Fri, 25 Jul 2008 01:48:39 -0700 Subject: markers: fix sparse integer as NULL pointer warning kernel/trace/trace_sysprof.c:164:20: warning: Using plain integer as NULL pointer Signed-off-by: Harvey Harrison Cc: Mathieu Desnoyers Signed-off-by: Andrew Morton Signed-off-by: Linus Torvalds --- kernel/trace/trace_sysprof.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'kernel/trace') diff --git a/kernel/trace/trace_sysprof.c b/kernel/trace/trace_sysprof.c index 63528086337c..ce2d723c10e1 100644 --- a/kernel/trace/trace_sysprof.c +++ b/kernel/trace/trace_sysprof.c @@ -161,7 +161,7 @@ static void timer_notify(struct pt_regs *regs, int cpu) __trace_special(tr, data, 2, regs->ip, 0); while (i < sample_max_depth) { - frame.next_fp = 0; + frame.next_fp = NULL; frame.return_address = 0; if (!copy_stack_frame(fp, &frame)) break; -- cgit v1.2.2 From 1fe371044b21b226b96a9dd959e971b50b28c78e Mon Sep 17 00:00:00 2001 From: Ingo Molnar Date: Sat, 26 Jul 2008 15:09:47 +0200 Subject: ftrace: fix modular build fix: ERROR: "start_critical_timings" [drivers/acpi/processor.ko] undefined! ERROR: "stop_critical_timings" [drivers/acpi/processor.ko] undefined! Signed-off-by: Ingo Molnar --- kernel/trace/trace_irqsoff.c | 2 ++ 1 file changed, 2 insertions(+) (limited to 'kernel/trace') diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c index b1e4a89b08eb..ece6cfb649fa 100644 --- a/kernel/trace/trace_irqsoff.c +++ b/kernel/trace/trace_irqsoff.c @@ -253,12 +253,14 @@ void start_critical_timings(void) if (preempt_trace() || irq_trace()) start_critical_timing(CALLER_ADDR0, CALLER_ADDR1); } +EXPORT_SYMBOL_GPL(start_critical_timings); void stop_critical_timings(void) { if (preempt_trace() || irq_trace()) stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1); } +EXPORT_SYMBOL_GPL(stop_critical_timings); #ifdef CONFIG_IRQSOFF_TRACER #ifdef CONFIG_PROVE_LOCKING -- cgit v1.2.2 From 605ccb73f6a1c891a16268b3a2923208fc637958 Mon Sep 17 00:00:00 2001 From: Andrea Righi Date: Sun, 27 Jul 2008 13:39:03 +0200 Subject: tracing: remove unused variable MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Remove the following warning with CONFIG_TRACING=y: kernel/trace/trace.c: In function ‘s_next’: kernel/trace/trace.c:1186: warning: unused variable ‘last_ent’ Signed-off-by: Andrea Righi Signed-off-by: Linus Torvalds --- kernel/trace/trace.c | 1 - 1 file changed, 1 deletion(-) (limited to 'kernel/trace') diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index fc20e09a6cb1..8f3fb3db61c3 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -1183,7 +1183,6 @@ static void *find_next_entry_inc(struct trace_iterator *iter) static void *s_next(struct seq_file *m, void *v, loff_t *pos) { struct trace_iterator *iter = m->private; - void *last_ent = iter->ent; int i = (int)*pos; void *ent; -- cgit v1.2.2 From 784e2d76007f90d69341b95967160c4fb7829299 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Mon, 28 Jul 2008 12:16:31 -0500 Subject: stop_machine: fix up ftrace.c Simple conversion. Signed-off-by: Rusty Russell Cc: Abhishek Sagar Cc: Ingo Molnar Cc: Steven Rostedt --- kernel/trace/ftrace.c | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) (limited to 'kernel/trace') diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c index 4231a3dc224a..f6e3af31b403 100644 --- a/kernel/trace/ftrace.c +++ b/kernel/trace/ftrace.c @@ -587,7 +587,7 @@ static int __ftrace_modify_code(void *data) static void ftrace_run_update_code(int command) { - stop_machine_run(__ftrace_modify_code, &command, NR_CPUS); + stop_machine(__ftrace_modify_code, &command, NULL); } void ftrace_disable_daemon(void) @@ -787,7 +787,7 @@ static int ftrace_update_code(void) !ftrace_enabled || !ftraced_trigger) return 0; - stop_machine_run(__ftrace_update_code, NULL, NR_CPUS); + stop_machine(__ftrace_update_code, NULL, NULL); return 1; } @@ -1564,7 +1564,7 @@ static int __init ftrace_dynamic_init(void) addr = (unsigned long)ftrace_record_ip; - stop_machine_run(ftrace_dyn_arch_init, &addr, NR_CPUS); + stop_machine(ftrace_dyn_arch_init, &addr, NULL); /* ftrace_dyn_arch_init places the return code in addr */ if (addr) { -- cgit v1.2.2