2017-03-13 10:10:03

by Qi Hou

[permalink] [raw]
Subject: [PATCH] lockdep: call trace_hardirqs_off after clearing hardirqs_enabled

The current order of calls within trace_hardirqs_off() would provoke an
"unannotated irqs-off" WARNING.

This warning was reported by check_flags() when it found that the hardirqs has
been disabled but the irq-flags state, hardirqs_enabled, has not been cleared.

Check_flags() is called via trace_hardirqs_off(), and trace_hardirqs_off() will
be called by functions kind of local_irq_disable() if CONFIG_TRACE_IRQFLAGS has
been enabled.

The calltrace from functions kind of local_irq_diasble() to check_flags()
simplied as below:

local_irq_disable()
|- trace_hardirqs_off()
|- trace_hardirqs_off_caller()
|- preemptirqsoff_hist()
|- __DO_TRACE()
|- rcu_dereference_sched()
|- rcu_read_lock_sched_held()
|- lock_is_held()
|- check_flags()

The order of calls within trace_hardirqs_off() can be simplified as below:

local_irq_disable()
|- raw_local_irq_disable()
|- trace_hardirqs_off()
|- trace_hardirqs_off() --> check_flags()
|- hardirqs_enabled = 0

We could find that the call to check_flags() has been made between disabling
hardirqs and clearing hardirqs_enabled. That will definitely cause an
"unannotated irqs-off" warning.

To fix this "unannotated irqs-off" warning, we must call trace_hardirqs_off()
after that we clear hardirqs_enabled.

Signed-off-by: Qi Hou <[email protected]>
---
kernel/locking/lockdep.c | 4 ++--
1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index 577f026..e8b35e4 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -2627,8 +2627,6 @@ __visible void trace_hardirqs_off_caller(unsigned long ip)
{
struct task_struct *curr = current;

- time_hardirqs_off(CALLER_ADDR0, ip);
-
if (unlikely(!debug_locks || current->lockdep_recursion))
return;

@@ -2649,6 +2647,8 @@ __visible void trace_hardirqs_off_caller(unsigned long ip)
debug_atomic_inc(hardirqs_off_events);
} else
debug_atomic_inc(redundant_hardirqs_off);
+
+ time_hardirqs_off(CALLER_ADDR0, ip);
}
EXPORT_SYMBOL(trace_hardirqs_off_caller);

--
1.9.1


2017-03-13 14:05:41

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH] lockdep: call trace_hardirqs_off after clearing hardirqs_enabled

On Mon, 13 Mar 2017 18:08:48 +0800
Qi Hou <[email protected]> wrote:

> The current order of calls within trace_hardirqs_off() would provoke an
> "unannotated irqs-off" WARNING.
>
> This warning was reported by check_flags() when it found that the hardirqs has
> been disabled but the irq-flags state, hardirqs_enabled, has not been cleared.
>
> Check_flags() is called via trace_hardirqs_off(), and trace_hardirqs_off() will
> be called by functions kind of local_irq_disable() if CONFIG_TRACE_IRQFLAGS has
> been enabled.
>
> The calltrace from functions kind of local_irq_diasble() to check_flags()
> simplied as below:
>
> local_irq_disable()
> |- trace_hardirqs_off()
> |- trace_hardirqs_off_caller()
> |- preemptirqsoff_hist()

There is no preemptirqsoff_hist() function in the kernel.

-- Steve

> |- __DO_TRACE()
> |- rcu_dereference_sched()
> |- rcu_read_lock_sched_held()
> |- lock_is_held()
> |- check_flags()
>
> The order of calls within trace_hardirqs_off() can be simplified as below:
>
> local_irq_disable()
> |- raw_local_irq_disable()
> |- trace_hardirqs_off()
> |- trace_hardirqs_off() --> check_flags()
> |- hardirqs_enabled = 0
>
> We could find that the call to check_flags() has been made between disabling
> hardirqs and clearing hardirqs_enabled. That will definitely cause an
> "unannotated irqs-off" warning.
>
> To fix this "unannotated irqs-off" warning, we must call trace_hardirqs_off()
> after that we clear hardirqs_enabled.
>
> Signed-off-by: Qi Hou <[email protected]>
> ---
> kernel/locking/lockdep.c | 4 ++--
> 1 file changed, 2 insertions(+), 2 deletions(-)
>
> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> index 577f026..e8b35e4 100644
> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -2627,8 +2627,6 @@ __visible void trace_hardirqs_off_caller(unsigned long ip)
> {
> struct task_struct *curr = current;
>
> - time_hardirqs_off(CALLER_ADDR0, ip);
> -
> if (unlikely(!debug_locks || current->lockdep_recursion))
> return;
>
> @@ -2649,6 +2647,8 @@ __visible void trace_hardirqs_off_caller(unsigned long ip)
> debug_atomic_inc(hardirqs_off_events);
> } else
> debug_atomic_inc(redundant_hardirqs_off);
> +
> + time_hardirqs_off(CALLER_ADDR0, ip);
> }
> EXPORT_SYMBOL(trace_hardirqs_off_caller);
>

2017-03-13 14:38:18

by Peter Zijlstra

[permalink] [raw]
Subject: Re: [PATCH] lockdep: call trace_hardirqs_off after clearing hardirqs_enabled


Thanks for Cc'ing me.

On Mon, Mar 13, 2017 at 06:08:48PM +0800, Qi Hou wrote:
> The current order of calls within trace_hardirqs_off() would provoke an
> "unannotated irqs-off" WARNING.
>
> This warning was reported by check_flags() when it found that the hardirqs has
> been disabled but the irq-flags state, hardirqs_enabled, has not been cleared.
>
> Check_flags() is called via trace_hardirqs_off(), and trace_hardirqs_off() will
> be called by functions kind of local_irq_disable() if CONFIG_TRACE_IRQFLAGS has
> been enabled.
>
> The calltrace from functions kind of local_irq_diasble() to check_flags()
> simplied as below:
>
> local_irq_disable()
> |- trace_hardirqs_off()
> |- trace_hardirqs_off_caller()
> |- preemptirqsoff_hist()
> |- __DO_TRACE()
> |- rcu_dereference_sched()
> |- rcu_read_lock_sched_held()
> |- lock_is_held()
> |- check_flags()
>
> The order of calls within trace_hardirqs_off() can be simplified as below:
>
> local_irq_disable()
> |- raw_local_irq_disable()
> |- trace_hardirqs_off()
> |- trace_hardirqs_off() --> check_flags()
> |- hardirqs_enabled = 0
>
> We could find that the call to check_flags() has been made between disabling
> hardirqs and clearing hardirqs_enabled. That will definitely cause an
> "unannotated irqs-off" warning.
>
> To fix this "unannotated irqs-off" warning, we must call trace_hardirqs_off()
> after that we clear hardirqs_enabled.

Here you say: "trace_hardirqs_off()"

> Signed-off-by: Qi Hou <[email protected]>
> ---
> kernel/locking/lockdep.c | 4 ++--
> 1 file changed, 2 insertions(+), 2 deletions(-)
>
> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
> index 577f026..e8b35e4 100644
> --- a/kernel/locking/lockdep.c
> +++ b/kernel/locking/lockdep.c
> @@ -2627,8 +2627,6 @@ __visible void trace_hardirqs_off_caller(unsigned long ip)
> {
> struct task_struct *curr = current;
>
> - time_hardirqs_off(CALLER_ADDR0, ip);

This is: "TIME_hardirqs_off()", notice the difference?

Care to try to write a changelog that makes sense?

2017-03-14 01:24:53

by Qi Hou

[permalink] [raw]
Subject: Re: [PATCH] lockdep: call trace_hardirqs_off after clearing hardirqs_enabled



On 2017年03月13日 22:05, Steven Rostedt wrote:
> On Mon, 13 Mar 2017 18:08:48 +0800
> Qi Hou <[email protected]> wrote:
>
>> The current order of calls within trace_hardirqs_off() would provoke an
>> "unannotated irqs-off" WARNING.
>>
>> This warning was reported by check_flags() when it found that the hardirqs has
>> been disabled but the irq-flags state, hardirqs_enabled, has not been cleared.
>>
>> Check_flags() is called via trace_hardirqs_off(), and trace_hardirqs_off() will
>> be called by functions kind of local_irq_disable() if CONFIG_TRACE_IRQFLAGS has
>> been enabled.
>>
>> The calltrace from functions kind of local_irq_diasble() to check_flags()
>> simplied as below:
>>
>> local_irq_disable()
>> |- trace_hardirqs_off()
>> |- trace_hardirqs_off_caller()
>> |- preemptirqsoff_hist()
> There is no preemptirqsoff_hist() function in the kernel.
Sorry, it's a mistake. It should have been
"trace_hardirqs_off_caller()", defined in file
kernel/locking/lockdep.c.

And it will call trace_preemptirqsoff_hist_rcuidle(),
trace_preemptirqsoff_hist_rcuidle will()
call check_flags().

I will correct it. And after carefully checking the patch, I will
re-send it.

Very very sorry for my mistake. That wasted your time.

---
Best regards,
Qi Hou
>
> -- Steve
>
>> |- __DO_TRACE()
>> |- rcu_dereference_sched()
>> |- rcu_read_lock_sched_held()
>> |- lock_is_held()
>> |- check_flags()
>>
>> The order of calls within trace_hardirqs_off() can be simplified as below:
>>
>> local_irq_disable()
>> |- raw_local_irq_disable()
>> |- trace_hardirqs_off()
>> |- trace_hardirqs_off() --> check_flags()
>> |- hardirqs_enabled = 0
>>
>> We could find that the call to check_flags() has been made between disabling
>> hardirqs and clearing hardirqs_enabled. That will definitely cause an
>> "unannotated irqs-off" warning.
>>
>> To fix this "unannotated irqs-off" warning, we must call trace_hardirqs_off()
>> after that we clear hardirqs_enabled.
>>
>> Signed-off-by: Qi Hou <[email protected]>
>> ---
>> kernel/locking/lockdep.c | 4 ++--
>> 1 file changed, 2 insertions(+), 2 deletions(-)
>>
>> diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
>> index 577f026..e8b35e4 100644
>> --- a/kernel/locking/lockdep.c
>> +++ b/kernel/locking/lockdep.c
>> @@ -2627,8 +2627,6 @@ __visible void trace_hardirqs_off_caller(unsigned long ip)
>> {
>> struct task_struct *curr = current;
>>
>> - time_hardirqs_off(CALLER_ADDR0, ip);
>> -
>> if (unlikely(!debug_locks || current->lockdep_recursion))
>> return;
>>
>> @@ -2649,6 +2647,8 @@ __visible void trace_hardirqs_off_caller(unsigned long ip)
>> debug_atomic_inc(hardirqs_off_events);
>> } else
>> debug_atomic_inc(redundant_hardirqs_off);
>> +
>> + time_hardirqs_off(CALLER_ADDR0, ip);
>> }
>> EXPORT_SYMBOL(trace_hardirqs_off_caller);
>>

--
Best regards,
Qi Hou
Phone number: +86-10-8477-8608
Address: Floor 15, Building B, Wangjing Plaza, No.9 Zhong-Huan Nanlu, Chaoyang District