Re: Runtime warnings in powerpc code

2018-12-31 Thread Benjamin Herrenschmidt
On Thu, 2018-12-27 at 11:05 -0800, Guenter Roeck wrote:
> Hi,
> 
> I am getting the attached runtime warnings when enabling certain debug
> options in powerpc code. The warnings are seen with pretty much all
> platforms, and all active kernel releases.
> 
> Question: Is it worthwhile to keep building / testing powerpc builds
> with the respective debug options enabled, and report it once in a while,
> or should I just disable the options ?

I've been fixing some issues with ppc32 and some of that stuff, I sent
some experimental patches updating 4xx and Christoph sent 8xx variants,
I still need to go through the other ones.

Cheers,
Ben.


> Thanks,
> Guenter
> 
> ---
> CONFIG_DEBUG_ATOMIC_SLEEP
> 
> [ cut here ]
> do not call blocking ops when !TASK_RUNNING; state=2 set at [<(ptrval)>]
> prepare_to_wait+0x54/0xe4
> WARNING: CPU: 0 PID: 1 at kernel/sched/core.c:6099 __might_sleep+0x94/0x9c
> Modules linked in:
> CPU: 0 PID: 1 Comm: init Not tainted 4.20.0-yocto-standard+ #1
> NIP:  c00667a0 LR: c00667a0 CTR: 
> REGS: cf8df8c0 TRAP: 0700   Not tainted  (4.20.0-yocto-standard+)
> MSR:  00029032   CR: 2822  XER: 2000
> 
> GPR00: c00667a0 cf8df970 cf8e 0062 c0af15c8 0007 fa1ae97e 
> 757148e2 
> GPR08: cf8de000    1f386000   
> cfd83c8c 
> GPR16: 0004 0004 0004  060c 000a cf8dfdb8 
> cf267804 
> GPR24: cf8dfd78 cf8dfd68 cfa88a20 cec70830 0001  01d3 
> c0b444cc 
> NIP [c00667a0] __might_sleep+0x94/0x9c
> LR [c00667a0] __might_sleep+0x94/0x9c
> Call Trace:
> [cf8df970] [c00667a0] __might_sleep+0x94/0x9c (unreliable)
> [cf8df990] [c05beddc] do_ide_request+0x48/0x6bc
> [cf8dfa10] [c0492bcc] __blk_run_queue+0x80/0x10c
> [cf8dfa20] [c049a938] blk_flush_plug_list+0x23c/0x258
> [cf8dfa60] [c006b888] io_schedule_prepare+0x44/0x5c
> [cf8dfa70] [c006b8c0] io_schedule+0x20/0x48
> [cf8dfa80] [c095e1ac] bit_wait_io+0x24/0x74
> [cf8dfa90] [c095dd94] __wait_on_bit+0xac/0x104
> [cf8dfab0] [c095de74] out_of_line_wait_on_bit+0x88/0x98
> [cf8dfae0] [c0229094] bh_submit_read+0xf8/0x104
> [cf8dfaf0] [c028b9a8] ext4_get_branch+0xdc/0x168
> [cf8dfb20] [c028c7fc] ext4_ind_map_blocks+0x2b0/0xc08
> [cf8dfc30] [c029551c] ext4_map_blocks+0x2e0/0x65c
> [cf8dfc80] [c02b8c84] ext4_mpage_readpages+0x5e8/0x97c
> [cf8dfd60] [c016c3cc] read_pages+0x60/0x1a0
> [cf8dfdb0] [c016c6e8] __do_page_cache_readahead+0x1dc/0x208
> [cf8dfe10] [c0159768] filemap_fault+0x418/0x834
> [cf8dfe50] [c02a00fc] ext4_filemap_fault+0x40/0x64
> [cf8dfe60] [c0198d0c] __do_fault+0x34/0xb8
> [cf8dfe70] [c019e264] handle_mm_fault+0xc44/0xf88
> [cf8dfef0] [c001a218] __do_page_fault+0x158/0x7b4
> [cf8dff40] [c00143b4] handle_page_fault+0x14/0x40
> --- interrupt: 301 at 0xb7904a70
> LR = 0xb78ef0c8
> Instruction dump:
> 7fe3fb78 bba10014 7c0803a6 38210020 4bfffd20 808a 3c60c0b0 3941 
> 7cc53378 3863a558 99490001 4bfd03bd <0fe0> 4bc0 7c0802a6 90010004 
> irq event stamp: 126702
> hardirqs last  enabled at (126701): [] console_unlock+0x434/0x5d0
> hardirqs last disabled at (126702): [] reenable_mmu+0x30/0x88
> softirqs last  enabled at (126552): [] __do_softirq+0x42c/0x4a0
> softirqs last disabled at (126529): [] irq_exit+0x104/0x108
> ---[ end trace 4f6c84b7815474d9 ]---
> 
> ---
> #if defined(CONFIG_PROVE_LOCKING) && defined(CONFIG_DEBUG_LOCKDEP) && \
> defined(CONFIG_TRACE_IRQFLAGS)
> 
> [ cut here ]
> DEBUG_LOCKS_WARN_ON(!current->hardirqs_enabled)
> WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:3762
> check_flags.part.25+0x1a0/0x1c4
> Modules linked in:
> CPU: 0 PID: 1 Comm: init Tainted: GW 4.20.0-yocto-standard+ #1
> NIP:  c00839f0 LR: c00839f0 CTR: 
> REGS: cf8dfe00 TRAP: 0700   Tainted: GW
> (4.20.0-yocto-standard+)
> MSR:  00021032   CR: 2828  XER: 2000
> 
> GPR00: c00839f0 cf8dfeb0 cf8e 002f 0001 c00938f4 c1425b76 
> 002f 
> GPR08: 1032  0001 0004 28282828   
> b7927688 
> GPR16:  bfe20a5c bfe20a58 0fe5fff8 1b38 10002178  
> b7929c20 
> GPR24: c095d81c 7c9319ee   b7929ae0 cf8e 9032 
> c0d2 
> NIP [c00839f0] check_flags.part.25+0x1a0/0x1c4
> LR [c00839f0] check_flags.part.25+0x1a0/0x1c4
> Call Trace:
> [cf8dfeb0] [c00839f0] check_flags.part.25+0x1a0/0x1c4 (unreliable)
> [cf8dfec0] [c0085f6c] lock_is_held_type+0x78/0xb4
> [cf8dfee0] [c095d35c] __schedule+0x6cc/0xb44
> [cf8dff30] [c095d81c] schedule+0x48/0xb8
> [cf8dff40] [c0014694] recheck+0x0/0x20
> --- interrupt: 501 at 0xb78f2850
> LR = 0xb78f2a24
> Instruction dump:
> 3c80c0b0 3c60c0af 3884d684 38635f94 4bfb3189 0fe0 4bfffec8 3c80c0b0 
> 3c60c0af 3884d668 38635f94 4bfb316d <0fe0> 4bfffefc 3c80c0b0 3c60c0af 
> irq event stamp: 127630
> hardirqs last  enabled at (127629): []
> _raw_spin_unlock_irq+0x3c/0x94
> hardirqs last disabled at (127630): [] reenable_mmu+0x30/0x88
> softirqs 

Re: Runtime warnings in powerpc code

2018-12-28 Thread Guenter Roeck
Hi Scott,

On Thu, Dec 27, 2018 at 07:31:33PM -0600, Scott Wood wrote:
> On Thu, 2018-12-27 at 11:05 -0800, Guenter Roeck wrote:
> > ---
> > CONFIG_DEBUG_ATOMIC_SLEEP
> > 
> > [ cut here ]
> > do not call blocking ops when !TASK_RUNNING; state=2 set at [<(ptrval)>]
> > prepare_to_wait+0x54/0xe4
> > WARNING: CPU: 0 PID: 1 at kernel/sched/core.c:6099 __might_sleep+0x94/0x9c
> > Modules linked in:
> > CPU: 0 PID: 1 Comm: init Not tainted 4.20.0-yocto-standard+ #1
> > NIP:  c00667a0 LR: c00667a0 CTR: 
> > REGS: cf8df8c0 TRAP: 0700   Not tainted  (4.20.0-yocto-standard+)
> > MSR:  00029032   CR: 2822  XER: 2000
> > 
> > GPR00: c00667a0 cf8df970 cf8e 0062 c0af15c8 0007 fa1ae97e
> > 757148e2 
> > GPR08: cf8de000    1f386000  
> > cfd83c8c 
> > GPR16: 0004 0004 0004  060c 000a cf8dfdb8
> > cf267804 
> > GPR24: cf8dfd78 cf8dfd68 cfa88a20 cec70830 0001  01d3
> > c0b444cc 
> > NIP [c00667a0] __might_sleep+0x94/0x9c
> > LR [c00667a0] __might_sleep+0x94/0x9c
> > Call Trace:
> > [cf8df970] [c00667a0] __might_sleep+0x94/0x9c (unreliable)
> > [cf8df990] [c05beddc] do_ide_request+0x48/0x6bc
> > [cf8dfa10] [c0492bcc] __blk_run_queue+0x80/0x10c
> > [cf8dfa20] [c049a938] blk_flush_plug_list+0x23c/0x258
> > [cf8dfa60] [c006b888] io_schedule_prepare+0x44/0x5c
> > [cf8dfa70] [c006b8c0] io_schedule+0x20/0x48
> > [cf8dfa80] [c095e1ac] bit_wait_io+0x24/0x74
> > [cf8dfa90] [c095dd94] __wait_on_bit+0xac/0x104
> > [cf8dfab0] [c095de74] out_of_line_wait_on_bit+0x88/0x98
> > [cf8dfae0] [c0229094] bh_submit_read+0xf8/0x104
> > [cf8dfaf0] [c028b9a8] ext4_get_branch+0xdc/0x168
> > [cf8dfb20] [c028c7fc] ext4_ind_map_blocks+0x2b0/0xc08
> > [cf8dfc30] [c029551c] ext4_map_blocks+0x2e0/0x65c
> > [cf8dfc80] [c02b8c84] ext4_mpage_readpages+0x5e8/0x97c
> > [cf8dfd60] [c016c3cc] read_pages+0x60/0x1a0
> > [cf8dfdb0] [c016c6e8] __do_page_cache_readahead+0x1dc/0x208
> > [cf8dfe10] [c0159768] filemap_fault+0x418/0x834
> > [cf8dfe50] [c02a00fc] ext4_filemap_fault+0x40/0x64
> > [cf8dfe60] [c0198d0c] __do_fault+0x34/0xb8
> > [cf8dfe70] [c019e264] handle_mm_fault+0xc44/0xf88
> > [cf8dfef0] [c001a218] __do_page_fault+0x158/0x7b4
> > [cf8dff40] [c00143b4] handle_page_fault+0x14/0x40
> > --- interrupt: 301 at 0xb7904a70
> > LR = 0xb78ef0c8
> > Instruction dump:
> > 7fe3fb78 bba10014 7c0803a6 38210020 4bfffd20 808a 3c60c0b0 3941 
> > 7cc53378 3863a558 99490001 4bfd03bd <0fe0> 4bc0 7c0802a6 90010004 
> > irq event stamp: 126702
> > hardirqs last  enabled at (126701): [] console_unlock+0x434/0x5d0
> > hardirqs last disabled at (126702): [] reenable_mmu+0x30/0x88
> > softirqs last  enabled at (126552): [] __do_softirq+0x42c/0x4a0
> > softirqs last disabled at (126529): [] irq_exit+0x104/0x108
> > ---[ end trace 4f6c84b7815474d9 ]---
> 
> This doesn't look PPC-specific, but rather IDE-specific.  Here's a similar one
> on x86:
> https://lkml.org/lkml/2016/12/12/596
> 
I wasn't sure, since I don't see the problem anywhere else.

Anyway, I'll disable the debug option in my tests if CONFIG_IDE is enabled.

> > ---
> > #if defined(CONFIG_PROVE_LOCKING) && defined(CONFIG_DEBUG_LOCKDEP) && \
> > defined(CONFIG_TRACE_IRQFLAGS)
> > 
> > [ cut here ]
> > DEBUG_LOCKS_WARN_ON(!current->hardirqs_enabled)
> > WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:3762
> 
> http://patchwork.ozlabs.org/patch/1016541/ should fix this.  It should also
> only be showing up on 32-bit, not all platforms.
> 
Looks like it. Unfortunately the patch does not apply to mainline.
I'll monitor its progress. And, yes, I should have been more
specific - both problem are only seen with ppc32 tests.

Thanks,
Guenter


Re: Runtime warnings in powerpc code

2018-12-27 Thread Scott Wood
On Thu, 2018-12-27 at 11:05 -0800, Guenter Roeck wrote:
> ---
> CONFIG_DEBUG_ATOMIC_SLEEP
> 
> [ cut here ]
> do not call blocking ops when !TASK_RUNNING; state=2 set at [<(ptrval)>]
> prepare_to_wait+0x54/0xe4
> WARNING: CPU: 0 PID: 1 at kernel/sched/core.c:6099 __might_sleep+0x94/0x9c
> Modules linked in:
> CPU: 0 PID: 1 Comm: init Not tainted 4.20.0-yocto-standard+ #1
> NIP:  c00667a0 LR: c00667a0 CTR: 
> REGS: cf8df8c0 TRAP: 0700   Not tainted  (4.20.0-yocto-standard+)
> MSR:  00029032   CR: 2822  XER: 2000
> 
> GPR00: c00667a0 cf8df970 cf8e 0062 c0af15c8 0007 fa1ae97e
> 757148e2 
> GPR08: cf8de000    1f386000  
> cfd83c8c 
> GPR16: 0004 0004 0004  060c 000a cf8dfdb8
> cf267804 
> GPR24: cf8dfd78 cf8dfd68 cfa88a20 cec70830 0001  01d3
> c0b444cc 
> NIP [c00667a0] __might_sleep+0x94/0x9c
> LR [c00667a0] __might_sleep+0x94/0x9c
> Call Trace:
> [cf8df970] [c00667a0] __might_sleep+0x94/0x9c (unreliable)
> [cf8df990] [c05beddc] do_ide_request+0x48/0x6bc
> [cf8dfa10] [c0492bcc] __blk_run_queue+0x80/0x10c
> [cf8dfa20] [c049a938] blk_flush_plug_list+0x23c/0x258
> [cf8dfa60] [c006b888] io_schedule_prepare+0x44/0x5c
> [cf8dfa70] [c006b8c0] io_schedule+0x20/0x48
> [cf8dfa80] [c095e1ac] bit_wait_io+0x24/0x74
> [cf8dfa90] [c095dd94] __wait_on_bit+0xac/0x104
> [cf8dfab0] [c095de74] out_of_line_wait_on_bit+0x88/0x98
> [cf8dfae0] [c0229094] bh_submit_read+0xf8/0x104
> [cf8dfaf0] [c028b9a8] ext4_get_branch+0xdc/0x168
> [cf8dfb20] [c028c7fc] ext4_ind_map_blocks+0x2b0/0xc08
> [cf8dfc30] [c029551c] ext4_map_blocks+0x2e0/0x65c
> [cf8dfc80] [c02b8c84] ext4_mpage_readpages+0x5e8/0x97c
> [cf8dfd60] [c016c3cc] read_pages+0x60/0x1a0
> [cf8dfdb0] [c016c6e8] __do_page_cache_readahead+0x1dc/0x208
> [cf8dfe10] [c0159768] filemap_fault+0x418/0x834
> [cf8dfe50] [c02a00fc] ext4_filemap_fault+0x40/0x64
> [cf8dfe60] [c0198d0c] __do_fault+0x34/0xb8
> [cf8dfe70] [c019e264] handle_mm_fault+0xc44/0xf88
> [cf8dfef0] [c001a218] __do_page_fault+0x158/0x7b4
> [cf8dff40] [c00143b4] handle_page_fault+0x14/0x40
> --- interrupt: 301 at 0xb7904a70
> LR = 0xb78ef0c8
> Instruction dump:
> 7fe3fb78 bba10014 7c0803a6 38210020 4bfffd20 808a 3c60c0b0 3941 
> 7cc53378 3863a558 99490001 4bfd03bd <0fe0> 4bc0 7c0802a6 90010004 
> irq event stamp: 126702
> hardirqs last  enabled at (126701): [] console_unlock+0x434/0x5d0
> hardirqs last disabled at (126702): [] reenable_mmu+0x30/0x88
> softirqs last  enabled at (126552): [] __do_softirq+0x42c/0x4a0
> softirqs last disabled at (126529): [] irq_exit+0x104/0x108
> ---[ end trace 4f6c84b7815474d9 ]---

This doesn't look PPC-specific, but rather IDE-specific.  Here's a similar one
on x86:
https://lkml.org/lkml/2016/12/12/596

> ---
> #if defined(CONFIG_PROVE_LOCKING) && defined(CONFIG_DEBUG_LOCKDEP) && \
> defined(CONFIG_TRACE_IRQFLAGS)
> 
> [ cut here ]
> DEBUG_LOCKS_WARN_ON(!current->hardirqs_enabled)
> WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:3762

http://patchwork.ozlabs.org/patch/1016541/ should fix this.  It should also
only be showing up on 32-bit, not all platforms.

-Scott




Runtime warnings in powerpc code

2018-12-27 Thread Guenter Roeck
Hi,

I am getting the attached runtime warnings when enabling certain debug
options in powerpc code. The warnings are seen with pretty much all
platforms, and all active kernel releases.

Question: Is it worthwhile to keep building / testing powerpc builds
with the respective debug options enabled, and report it once in a while,
or should I just disable the options ?

Thanks,
Guenter

---
CONFIG_DEBUG_ATOMIC_SLEEP

[ cut here ]
do not call blocking ops when !TASK_RUNNING; state=2 set at [<(ptrval)>]
prepare_to_wait+0x54/0xe4
WARNING: CPU: 0 PID: 1 at kernel/sched/core.c:6099 __might_sleep+0x94/0x9c
Modules linked in:
CPU: 0 PID: 1 Comm: init Not tainted 4.20.0-yocto-standard+ #1
NIP:  c00667a0 LR: c00667a0 CTR: 
REGS: cf8df8c0 TRAP: 0700   Not tainted  (4.20.0-yocto-standard+)
MSR:  00029032   CR: 2822  XER: 2000

GPR00: c00667a0 cf8df970 cf8e 0062 c0af15c8 0007 fa1ae97e 757148e2 
GPR08: cf8de000    1f386000   cfd83c8c 
GPR16: 0004 0004 0004  060c 000a cf8dfdb8 cf267804 
GPR24: cf8dfd78 cf8dfd68 cfa88a20 cec70830 0001  01d3 c0b444cc 
NIP [c00667a0] __might_sleep+0x94/0x9c
LR [c00667a0] __might_sleep+0x94/0x9c
Call Trace:
[cf8df970] [c00667a0] __might_sleep+0x94/0x9c (unreliable)
[cf8df990] [c05beddc] do_ide_request+0x48/0x6bc
[cf8dfa10] [c0492bcc] __blk_run_queue+0x80/0x10c
[cf8dfa20] [c049a938] blk_flush_plug_list+0x23c/0x258
[cf8dfa60] [c006b888] io_schedule_prepare+0x44/0x5c
[cf8dfa70] [c006b8c0] io_schedule+0x20/0x48
[cf8dfa80] [c095e1ac] bit_wait_io+0x24/0x74
[cf8dfa90] [c095dd94] __wait_on_bit+0xac/0x104
[cf8dfab0] [c095de74] out_of_line_wait_on_bit+0x88/0x98
[cf8dfae0] [c0229094] bh_submit_read+0xf8/0x104
[cf8dfaf0] [c028b9a8] ext4_get_branch+0xdc/0x168
[cf8dfb20] [c028c7fc] ext4_ind_map_blocks+0x2b0/0xc08
[cf8dfc30] [c029551c] ext4_map_blocks+0x2e0/0x65c
[cf8dfc80] [c02b8c84] ext4_mpage_readpages+0x5e8/0x97c
[cf8dfd60] [c016c3cc] read_pages+0x60/0x1a0
[cf8dfdb0] [c016c6e8] __do_page_cache_readahead+0x1dc/0x208
[cf8dfe10] [c0159768] filemap_fault+0x418/0x834
[cf8dfe50] [c02a00fc] ext4_filemap_fault+0x40/0x64
[cf8dfe60] [c0198d0c] __do_fault+0x34/0xb8
[cf8dfe70] [c019e264] handle_mm_fault+0xc44/0xf88
[cf8dfef0] [c001a218] __do_page_fault+0x158/0x7b4
[cf8dff40] [c00143b4] handle_page_fault+0x14/0x40
--- interrupt: 301 at 0xb7904a70
LR = 0xb78ef0c8
Instruction dump:
7fe3fb78 bba10014 7c0803a6 38210020 4bfffd20 808a 3c60c0b0 3941 
7cc53378 3863a558 99490001 4bfd03bd <0fe0> 4bc0 7c0802a6 90010004 
irq event stamp: 126702
hardirqs last  enabled at (126701): [] console_unlock+0x434/0x5d0
hardirqs last disabled at (126702): [] reenable_mmu+0x30/0x88
softirqs last  enabled at (126552): [] __do_softirq+0x42c/0x4a0
softirqs last disabled at (126529): [] irq_exit+0x104/0x108
---[ end trace 4f6c84b7815474d9 ]---

---
#if defined(CONFIG_PROVE_LOCKING) && defined(CONFIG_DEBUG_LOCKDEP) && \
defined(CONFIG_TRACE_IRQFLAGS)

[ cut here ]
DEBUG_LOCKS_WARN_ON(!current->hardirqs_enabled)
WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:3762
check_flags.part.25+0x1a0/0x1c4
Modules linked in:
CPU: 0 PID: 1 Comm: init Tainted: GW 4.20.0-yocto-standard+ #1
NIP:  c00839f0 LR: c00839f0 CTR: 
REGS: cf8dfe00 TRAP: 0700   Tainted: GW
(4.20.0-yocto-standard+)
MSR:  00021032   CR: 2828  XER: 2000

GPR00: c00839f0 cf8dfeb0 cf8e 002f 0001 c00938f4 c1425b76 002f 
GPR08: 1032  0001 0004 28282828   b7927688 
GPR16:  bfe20a5c bfe20a58 0fe5fff8 1b38 10002178  b7929c20 
GPR24: c095d81c 7c9319ee   b7929ae0 cf8e 9032 c0d2 
NIP [c00839f0] check_flags.part.25+0x1a0/0x1c4
LR [c00839f0] check_flags.part.25+0x1a0/0x1c4
Call Trace:
[cf8dfeb0] [c00839f0] check_flags.part.25+0x1a0/0x1c4 (unreliable)
[cf8dfec0] [c0085f6c] lock_is_held_type+0x78/0xb4
[cf8dfee0] [c095d35c] __schedule+0x6cc/0xb44
[cf8dff30] [c095d81c] schedule+0x48/0xb8
[cf8dff40] [c0014694] recheck+0x0/0x20
--- interrupt: 501 at 0xb78f2850
LR = 0xb78f2a24
Instruction dump:
3c80c0b0 3c60c0af 3884d684 38635f94 4bfb3189 0fe0 4bfffec8 3c80c0b0 
3c60c0af 3884d668 38635f94 4bfb316d <0fe0> 4bfffefc 3c80c0b0 3c60c0af 
irq event stamp: 127630
hardirqs last  enabled at (127629): []
_raw_spin_unlock_irq+0x3c/0x94
hardirqs last disabled at (127630): [] reenable_mmu+0x30/0x88
softirqs last  enabled at (127402): [] __do_softirq+0x42c/0x4a0
softirqs last disabled at (127393): [] irq_exit+0x104/0x108
---[ end trace 4f6c84b7815474da ]---
possible reason: unannotated irqs-on.
irq event stamp: 127630
hardirqs last  enabled at (127629): [] _raw_spin_unlock_irq+0x3c/0x94
hardirqs last disabled at (127630): [] reenable_mmu+0x30/0x88
softirqs last  enabled at (127402): [] __do_softirq+0x42c/0x4a0
softirqs last disabled at (127393): [] irq_exit+0x104/0x108