* mmotm 2018-08-23-17-26 uploaded
[not found] ` <049c3fa9-f888-6a2d-413b-872992b269f9@gmail.com>
@ 2018-08-29 23:22 ` Andrew Morton
2018-08-30 1:00 ` Jia He
0 siblings, 1 reply; 4+ messages in thread
From: Andrew Morton @ 2018-08-29 23:22 UTC (permalink / raw)
To: linux-arm-kernel
On Tue, 28 Aug 2018 12:20:46 +0800 Jia He <hejianet@gmail.com> wrote:
> Hi Andrew
> FYI,I watched a lockdep warning based on your mmotm master branch[1]
Thanks. We'll need help from ARM peeps on this please.
> [ 6.692731] ------------[ cut here ]------------
> [ 6.696391] DEBUG_LOCKS_WARN_ON(!current->hardirqs_enabled)
> [ 6.696404] WARNING: CPU: 3 PID: 320 at kernel/locking/lockdep.c:3845
> check_flags.part.38+0x9c/0x16c
> [ 6.711082] Modules linked in:
> [ 6.714101] CPU: 3 PID: 320 Comm: modprobe Not tainted 4.18.0-rc4-mm1+ #56
> [ 6.720956] Hardware name: WIWYNN HXT REP-1 System H001-00001-0/HXT REP-1
> CRB, BIOS 0ACJA530 03/20/2018
> [ 6.730332] pstate: 60400085 (nZCv daIf +PAN -UAO)
> [ 6.735106] pc : check_flags.part.38+0x9c/0x16c
> [ 6.739619] lr : check_flags.part.38+0x9c/0x16c
> [ 6.744133] sp : ffff80178536fbf0
> [ 6.747432] x29: ffff80178536fbf0 x28: ffff8017905a1b00
> [ 6.752727] x27: 0000000000000002 x26: 0000000000000000
> [ 6.758022] x25: ffff000008abeb14 x24: 0000000000000000
> [ 6.763317] x23: 0000000000000001 x22: 0000000000000001
> [ 6.768612] x21: 0000000000000001 x20: 0000000000000000
> [ 6.773908] x19: ffff00000a041000 x18: 0000000000000000
> [ 6.779202] x17: 0000000000000000 x16: 0000000000000000
> [ 6.784498] x15: 0000000000000000 x14: 0000000000000000
> [ 6.789793] x13: ffff000008d6b190 x12: 752ce9eb60de3f00
> [ 6.795088] x11: ffff80178536f7f0 x10: ffff80178536f7f0
> [ 6.800383] x9 : 00000000ffffffd0 x8 : 0000000000000000
> [ 6.805678] x7 : ffff00000816fe48 x6 : ffff801794ba62b8
> [ 6.810973] x5 : 0000000000000000 x4 : 0000000000000000
> [ 6.816269] x3 : ffffffffffffffff x2 : ffff0000091ed988
> [ 6.821564] x1 : 752ce9eb60de3f00 x0 : 752ce9eb60de3f00
> [ 6.826859] Call trace:
> [ 6.829290] check_flags.part.38+0x9c/0x16c
> [ 6.833457] lock_acquire+0x12c/0x280
> [ 6.837104] down_read_trylock+0x78/0x98
> [ 6.841011] do_page_fault+0x150/0x480
> [ 6.844742] do_translation_fault+0x74/0x80
> [ 6.848909] do_mem_abort+0x60/0x108
> [ 6.852467] el0_da+0x24/0x28
> [ 6.855418] irq event stamp: 250
> [ 6.858633] hardirqs last enabled at (249): [<ffff00000830e518>]
> mem_cgroup_commit_charge+0x9c/0x13c
> [ 6.867833] hardirqs last disabled at (250): [<ffff000008095f40>]
> el0_svc_handler+0xc4/0x16c
> [ 6.876252] softirqs last enabled at (242): [<ffff000008081c48>]
> __do_softirq+0x2f8/0x554
> [ 6.884501] softirqs last disabled at (229): [<ffff0000080f1bec>]
> irq_exit+0x180/0x194
> [ 6.892399] ---[ end trace b45768f94a7b7d9f ]---
> [ 6.896998] possible reason: unannotated irqs-on.
> [ 6.901685] irq event stamp: 250
> [ 6.904898] hardirqs last enabled at (249): [<ffff00000830e518>]
> mem_cgroup_commit_charge+0x9c/0x13c
> [ 6.914100] hardirqs last disabled at (250): [<ffff000008095f40>]
> el0_svc_handler+0xc4/0x16c
> [ 6.922519] softirqs last enabled at (242): [<ffff000008081c48>]
> __do_softirq+0x2f8/0x554
> [ 6.930766] softirqs last disabled at (229): [<ffff0000080f1bec>]
> irq_exit+0x180/0x194
> [ 7.023827] Initialise system trusted keyrings
> [ 7.027414] workingset: timestamp_bits=45 max_order=25 bucket_order=0
Lockdep says current->hardirqs_enabled is false and that is indeed an
error. arch/arm64/kernel/entry.S:el0_da does enable_daif which might
be an attempt to enable hardirqs, but how does that get propagated into
lockdep's ->hardirqs_enabled? By calling
local_irq_enable()->trace_hardirqs_on(), but that's C, not assembler.
And what changed to cause this?
I dunno anything. Help!
> I thought the root cause might be at [2] which seems not in your branch yet.
>
> [1] http://git.cmpxchg.org/cgit.cgi/linux-mmotm.git
> [2]
> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit?id=efd112
I agree, that doesn't look like the culprit. But something may well
have gone wrong in "the recent conversion of the syscall entry/exit
code to C".
>
> ...
>
^ permalink raw reply [flat|nested] 4+ messages in thread
* mmotm 2018-08-23-17-26 uploaded
2018-08-29 23:22 ` mmotm 2018-08-23-17-26 uploaded Andrew Morton
@ 2018-08-30 1:00 ` Jia He
2018-08-30 6:26 ` Jia He
0 siblings, 1 reply; 4+ messages in thread
From: Jia He @ 2018-08-30 1:00 UTC (permalink / raw)
To: linux-arm-kernel
On 8/30/2018 7:22 AM, Andrew Morton Wrote:
> On Tue, 28 Aug 2018 12:20:46 +0800 Jia He <hejianet@gmail.com> wrote:
>
>> Hi Andrew
>> FYI,I watched a lockdep warning based on your mmotm master branch[1]
>
> Thanks. We'll need help from ARM peeps on this please.
>
>> [ 6.692731] ------------[ cut here ]------------
>> [ 6.696391] DEBUG_LOCKS_WARN_ON(!current->hardirqs_enabled)
>> [ 6.696404] WARNING: CPU: 3 PID: 320 at kernel/locking/lockdep.c:3845
>> check_flags.part.38+0x9c/0x16c
>> [ 6.711082] Modules linked in:
>> [ 6.714101] CPU: 3 PID: 320 Comm: modprobe Not tainted 4.18.0-rc4-mm1+ #56
>> [ 6.720956] Hardware name: WIWYNN HXT REP-1 System H001-00001-0/HXT REP-1
>> CRB, BIOS 0ACJA530 03/20/2018
>> [ 6.730332] pstate: 60400085 (nZCv daIf +PAN -UAO)
>> [ 6.735106] pc : check_flags.part.38+0x9c/0x16c
>> [ 6.739619] lr : check_flags.part.38+0x9c/0x16c
>> [ 6.744133] sp : ffff80178536fbf0
>> [ 6.747432] x29: ffff80178536fbf0 x28: ffff8017905a1b00
>> [ 6.752727] x27: 0000000000000002 x26: 0000000000000000
>> [ 6.758022] x25: ffff000008abeb14 x24: 0000000000000000
>> [ 6.763317] x23: 0000000000000001 x22: 0000000000000001
>> [ 6.768612] x21: 0000000000000001 x20: 0000000000000000
>> [ 6.773908] x19: ffff00000a041000 x18: 0000000000000000
>> [ 6.779202] x17: 0000000000000000 x16: 0000000000000000
>> [ 6.784498] x15: 0000000000000000 x14: 0000000000000000
>> [ 6.789793] x13: ffff000008d6b190 x12: 752ce9eb60de3f00
>> [ 6.795088] x11: ffff80178536f7f0 x10: ffff80178536f7f0
>> [ 6.800383] x9 : 00000000ffffffd0 x8 : 0000000000000000
>> [ 6.805678] x7 : ffff00000816fe48 x6 : ffff801794ba62b8
>> [ 6.810973] x5 : 0000000000000000 x4 : 0000000000000000
>> [ 6.816269] x3 : ffffffffffffffff x2 : ffff0000091ed988
>> [ 6.821564] x1 : 752ce9eb60de3f00 x0 : 752ce9eb60de3f00
>> [ 6.826859] Call trace:
>> [ 6.829290] check_flags.part.38+0x9c/0x16c
>> [ 6.833457] lock_acquire+0x12c/0x280
>> [ 6.837104] down_read_trylock+0x78/0x98
>> [ 6.841011] do_page_fault+0x150/0x480
>> [ 6.844742] do_translation_fault+0x74/0x80
>> [ 6.848909] do_mem_abort+0x60/0x108
>> [ 6.852467] el0_da+0x24/0x28
>> [ 6.855418] irq event stamp: 250
>> [ 6.858633] hardirqs last enabled at (249): [<ffff00000830e518>]
>> mem_cgroup_commit_charge+0x9c/0x13c
>> [ 6.867833] hardirqs last disabled at (250): [<ffff000008095f40>]
>> el0_svc_handler+0xc4/0x16c
>> [ 6.876252] softirqs last enabled at (242): [<ffff000008081c48>]
>> __do_softirq+0x2f8/0x554
>> [ 6.884501] softirqs last disabled at (229): [<ffff0000080f1bec>]
>> irq_exit+0x180/0x194
>> [ 6.892399] ---[ end trace b45768f94a7b7d9f ]---
>> [ 6.896998] possible reason: unannotated irqs-on.
>> [ 6.901685] irq event stamp: 250
>> [ 6.904898] hardirqs last enabled at (249): [<ffff00000830e518>]
>> mem_cgroup_commit_charge+0x9c/0x13c
>> [ 6.914100] hardirqs last disabled at (250): [<ffff000008095f40>]
>> el0_svc_handler+0xc4/0x16c
>> [ 6.922519] softirqs last enabled at (242): [<ffff000008081c48>]
>> __do_softirq+0x2f8/0x554
>> [ 6.930766] softirqs last disabled at (229): [<ffff0000080f1bec>]
>> irq_exit+0x180/0x194
>> [ 7.023827] Initialise system trusted keyrings
>> [ 7.027414] workingset: timestamp_bits=45 max_order=25 bucket_order=0
>
> Lockdep says current->hardirqs_enabled is false and that is indeed an
> error. arch/arm64/kernel/entry.S:el0_da does enable_daif which might
> be an attempt to enable hardirqs, but how does that get propagated into
> lockdep's ->hardirqs_enabled? By calling
> local_irq_enable()->trace_hardirqs_on(), but that's C, not assembler.
>
> And what changed to cause this?
>
> I dunno anything. Help!
>
>> I thought the root cause might be at [2] which seems not in your branch yet.
>>
>> [1] http://git.cmpxchg.org/cgit.cgi/linux-mmotm.git
>> [2]
>> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit?id=efd112
>
> I agree, that doesn't look like the culprit. But something may well
> have gone wrong in "the recent conversion of the syscall entry/exit
> code to C".
Sorry for my unclearly previously description.
1. no such lockdep warning in latest mainline kernel git tree.
2. there is a 100% producible warning based on your latest mmotm tree
3. after applying the commit efd112 based on your mmotm tree, the warning
disappearred
I will do some further digging to answer your question if no other experts' help
--
Cheers,
Jia
^ permalink raw reply [flat|nested] 4+ messages in thread
* mmotm 2018-08-23-17-26 uploaded
2018-08-30 1:00 ` Jia He
@ 2018-08-30 6:26 ` Jia He
2018-08-30 9:22 ` Will Deacon
0 siblings, 1 reply; 4+ messages in thread
From: Jia He @ 2018-08-30 6:26 UTC (permalink / raw)
To: linux-arm-kernel
Hi Andrew
On 8/30/2018 9:00 AM, Jia He Wrote:
>
>
> On 8/30/2018 7:22 AM, Andrew Morton Wrote:
>> On Tue, 28 Aug 2018 12:20:46 +0800 Jia He <hejianet@gmail.com> wrote:
>>
>>> Hi Andrew
>>> FYI,I watched a lockdep warning based on your mmotm master branch[1]
>>
>> Thanks. We'll need help from ARM peeps on this please.
>>
>>> [ 6.692731] ------------[ cut here ]------------
>>> [ 6.696391] DEBUG_LOCKS_WARN_ON(!current->hardirqs_enabled)
>>> [ 6.696404] WARNING: CPU: 3 PID: 320 at kernel/locking/lockdep.c:3845
>>> check_flags.part.38+0x9c/0x16c
>>> [ 6.711082] Modules linked in:
>>> [ 6.714101] CPU: 3 PID: 320 Comm: modprobe Not tainted 4.18.0-rc4-mm1+ #56
>>> [ 6.720956] Hardware name: WIWYNN HXT REP-1 System H001-00001-0/HXT REP-1
>>> CRB, BIOS 0ACJA530 03/20/2018
>>> [ 6.730332] pstate: 60400085 (nZCv daIf +PAN -UAO)
>>> [ 6.735106] pc : check_flags.part.38+0x9c/0x16c
>>> [ 6.739619] lr : check_flags.part.38+0x9c/0x16c
>>> [ 6.744133] sp : ffff80178536fbf0
>>> [ 6.747432] x29: ffff80178536fbf0 x28: ffff8017905a1b00
>>> [ 6.752727] x27: 0000000000000002 x26: 0000000000000000
>>> [ 6.758022] x25: ffff000008abeb14 x24: 0000000000000000
>>> [ 6.763317] x23: 0000000000000001 x22: 0000000000000001
>>> [ 6.768612] x21: 0000000000000001 x20: 0000000000000000
>>> [ 6.773908] x19: ffff00000a041000 x18: 0000000000000000
>>> [ 6.779202] x17: 0000000000000000 x16: 0000000000000000
>>> [ 6.784498] x15: 0000000000000000 x14: 0000000000000000
>>> [ 6.789793] x13: ffff000008d6b190 x12: 752ce9eb60de3f00
>>> [ 6.795088] x11: ffff80178536f7f0 x10: ffff80178536f7f0
>>> [ 6.800383] x9 : 00000000ffffffd0 x8 : 0000000000000000
>>> [ 6.805678] x7 : ffff00000816fe48 x6 : ffff801794ba62b8
>>> [ 6.810973] x5 : 0000000000000000 x4 : 0000000000000000
>>> [ 6.816269] x3 : ffffffffffffffff x2 : ffff0000091ed988
>>> [ 6.821564] x1 : 752ce9eb60de3f00 x0 : 752ce9eb60de3f00
>>> [ 6.826859] Call trace:
>>> [ 6.829290] check_flags.part.38+0x9c/0x16c
>>> [ 6.833457] lock_acquire+0x12c/0x280
>>> [ 6.837104] down_read_trylock+0x78/0x98
>>> [ 6.841011] do_page_fault+0x150/0x480
>>> [ 6.844742] do_translation_fault+0x74/0x80
>>> [ 6.848909] do_mem_abort+0x60/0x108
>>> [ 6.852467] el0_da+0x24/0x28
>>> [ 6.855418] irq event stamp: 250
>>> [ 6.858633] hardirqs last enabled at (249): [<ffff00000830e518>]
>>> mem_cgroup_commit_charge+0x9c/0x13c
>>> [ 6.867833] hardirqs last disabled at (250): [<ffff000008095f40>]
>>> el0_svc_handler+0xc4/0x16c
>>> [ 6.876252] softirqs last enabled at (242): [<ffff000008081c48>]
>>> __do_softirq+0x2f8/0x554
>>> [ 6.884501] softirqs last disabled at (229): [<ffff0000080f1bec>]
>>> irq_exit+0x180/0x194
>>> [ 6.892399] ---[ end trace b45768f94a7b7d9f ]---
>>> [ 6.896998] possible reason: unannotated irqs-on.
>>> [ 6.901685] irq event stamp: 250
>>> [ 6.904898] hardirqs last enabled at (249): [<ffff00000830e518>]
>>> mem_cgroup_commit_charge+0x9c/0x13c
>>> [ 6.914100] hardirqs last disabled at (250): [<ffff000008095f40>]
>>> el0_svc_handler+0xc4/0x16c
>>> [ 6.922519] softirqs last enabled at (242): [<ffff000008081c48>]
>>> __do_softirq+0x2f8/0x554
>>> [ 6.930766] softirqs last disabled at (229): [<ffff0000080f1bec>]
>>> irq_exit+0x180/0x194
>>> [ 7.023827] Initialise system trusted keyrings
>>> [ 7.027414] workingset: timestamp_bits=45 max_order=25 bucket_order=0
>>
>> Lockdep says current->hardirqs_enabled is false and that is indeed an
>> error. arch/arm64/kernel/entry.S:el0_da does enable_daif which might
>> be an attempt to enable hardirqs, but how does that get propagated into
>> lockdep's ->hardirqs_enabled? By calling
>> local_irq_enable()->trace_hardirqs_on(), but that's C, not assembler.
>>
>> And what changed to cause this?
>>
>> I dunno anything. Help!
>>
>>> I thought the root cause might be at [2] which seems not in your branch yet.
>>>
>>> [1] http://git.cmpxchg.org/cgit.cgi/linux-mmotm.git
>>> [2]
>>> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit?id=efd112
>>
>> I agree, that doesn't look like the culprit. But something may well
>> have gone wrong in "the recent conversion of the syscall entry/exit
>> code to C".
> Sorry for my unclearly previously description.
> 1. no such lockdep warning in latest mainline kernel git tree.
> 2. there is a 100% producible warning based on your latest mmotm tree
> 3. after applying the commit efd112 based on your mmotm tree, the warning
> disappearred
>
> I will do some further digging to answer your question if no other experts' help
>
1. in el0_svc->el0_svc_common, without commit efd112
local_daif_mask(); //disable the irq and trace irq off
flags = current_thread_info()->flags;
if (!has_syscall_work(flags))
------------ //1
return;
If el0_svc_common enters the logic at line 1, the irq is disabled and
current->hardirqs_enabled is 0.
2. then it goes to el0_da
in el0_da, it enables the irq without changing current->hardirqs_enabled to 1
3. goes to el0_da->do_mem_abort->... the lockdep warning happens
The commit efd112 fixes it by invoking trace_hardirqs_off at line 1.
It closes the inconsistency window.
Cheers,
Jia
--
Cheers,
Jia
^ permalink raw reply [flat|nested] 4+ messages in thread
* mmotm 2018-08-23-17-26 uploaded
2018-08-30 6:26 ` Jia He
@ 2018-08-30 9:22 ` Will Deacon
0 siblings, 0 replies; 4+ messages in thread
From: Will Deacon @ 2018-08-30 9:22 UTC (permalink / raw)
To: linux-arm-kernel
On Thu, Aug 30, 2018 at 02:26:51PM +0800, Jia He wrote:
> On 8/30/2018 9:00 AM, Jia He Wrote:
> > On 8/30/2018 7:22 AM, Andrew Morton Wrote:
> >> On Tue, 28 Aug 2018 12:20:46 +0800 Jia He <hejianet@gmail.com> wrote:
> >>> FYI,I watched a lockdep warning based on your mmotm master branch[1]
> >>
> >> Thanks. We'll need help from ARM peeps on this please.
> >>
> >>> [ 6.692731] ------------[ cut here ]------------
> >>> [ 6.696391] DEBUG_LOCKS_WARN_ON(!current->hardirqs_enabled)
[...]
> >>> I thought the root cause might be at [2] which seems not in your branch yet.
> >>>
> >>> [1] http://git.cmpxchg.org/cgit.cgi/linux-mmotm.git
> >>> [2]
> >>> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit?id=efd112
> >>
> >> I agree, that doesn't look like the culprit. But something may well
> >> have gone wrong in "the recent conversion of the syscall entry/exit
> >> code to C".
> > Sorry for my unclearly previously description.
> > 1. no such lockdep warning in latest mainline kernel git tree.
> > 2. there is a 100% producible warning based on your latest mmotm tree
> > 3. after applying the commit efd112 based on your mmotm tree, the warning
> > disappearred
> >
> > I will do some further digging to answer your question if no other experts' help
> >
> 1. in el0_svc->el0_svc_common, without commit efd112
> local_daif_mask(); //disable the irq and trace irq off
> flags = current_thread_info()->flags;
> if (!has_syscall_work(flags))
> ------------ //1
> return;
> If el0_svc_common enters the logic at line 1, the irq is disabled and
> current->hardirqs_enabled is 0.
>
> 2. then it goes to el0_da
> in el0_da, it enables the irq without changing current->hardirqs_enabled to 1
>
> 3. goes to el0_da->do_mem_abort->... the lockdep warning happens
>
> The commit efd112 fixes it by invoking trace_hardirqs_off at line 1.
> It closes the inconsistency window.
Right, we fixed this last month in commit efd112353bf7 ("arm64: svc: Ensure
hardirq tracing is updated before return"). Is there anything more you need
from us on the Arm side?
Will
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2018-08-30 9:22 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
[not found] <20180824002731.XMNCl%akpm@linux-foundation.org>
[not found] ` <049c3fa9-f888-6a2d-413b-872992b269f9@gmail.com>
2018-08-29 23:22 ` mmotm 2018-08-23-17-26 uploaded Andrew Morton
2018-08-30 1:00 ` Jia He
2018-08-30 6:26 ` Jia He
2018-08-30 9:22 ` Will Deacon
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).