2021-07-13 14:08:45

by kernel test robot

[permalink] [raw]
Subject: [mm/vmalloc] 5c1f4e690e: BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c



Greeting,

FYI, we noticed the following commit (built with gcc-9):

commit: 5c1f4e690eecc795b2e4d4408e87302040fceca4 ("mm/vmalloc: switch to bulk allocator in __vmalloc_area_node()")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master


in testcase: trinity
version: trinity-static-x86_64-x86_64-1c734c75-1_2020-01-06
with following parameters:

number: 99999
group: group-02

test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/


on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+----------------------------------------------------------------------+------------+------------+
| | a2afc59fb2 | 5c1f4e690e |
+----------------------------------------------------------------------+------------+------------+
| BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c | 0 | 54 |
+----------------------------------------------------------------------+------------+------------+


If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>


[ 131.014885] BUG: sleeping function called from invalid context at mm/page_alloc.c:4992
[ 131.019428] in_atomic(): 0, irqs_disabled(): 1, non_block: 0, pid: 2928, name: trinity-c6
[ 131.023996] no locks held by trinity-c6/2928.
[ 131.027987] irq event stamp: 283042
[ 131.031844] hardirqs last enabled at (283041): [<ffffffff8643af22>] _raw_spin_unlock_irqrestore+0x42/0x50
[ 131.036625] hardirqs last disabled at (283042): [<ffffffff81656d71>] __alloc_pages_bulk+0xae1/0xf20
[ 131.041305] softirqs last enabled at (281858): [<ffffffff86800623>] __do_softirq+0x623/0x9db
[ 131.046157] softirqs last disabled at (281853): [<ffffffff8116dfee>] irq_exit_rcu+0xce/0xf0
[ 131.050925] CPU: 0 PID: 2928 Comm: trinity-c6 Not tainted 5.13.0+ #1
[ 131.055391] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 131.060133] Call Trace:
[ 131.064110] dump_stack+0xa5/0xe6
[ 131.068192] ___might_sleep.cold+0x147/0x177
[ 131.072324] __alloc_pages+0x462/0x650
[ 131.076397] ? kvm_sched_clock_read+0x14/0x30
[ 131.080466] ? __kernel_text_address+0x9/0x30
[ 131.084443] ? __alloc_pages_slowpath+0x2020/0x2020
[ 131.088662] ? arch_stack_walk+0x71/0xb0
[ 131.092667] stack_depot_save+0x390/0x4c0
[ 131.096595] ? stack_trace_snprint+0xd0/0xd0
[ 131.100577] save_stack+0x107/0x170
[ 131.104276] ? register_early_stack+0x80/0x80
[ 131.108443] ? __alloc_pages_bulk+0x7fa/0xf20
[ 131.112258] ? __vmalloc_area_node+0x1b3/0x5e0
[ 131.116190] ? __vmalloc_node_range+0xac/0x150
[ 131.119901] ? vmalloc+0x62/0x80
[ 131.123364] ? netlink_sendmsg+0x4df/0xb50
[ 131.126817] ? sock_sendmsg+0xa6/0xe0
[ 131.130170] ? sock_write_iter+0x1fe/0x340
[ 131.133599] ? do_iter_readv_writev+0x332/0x6b0
[ 131.137030] ? do_iter_write+0x12c/0x5c0
[ 131.140440] ? vfs_writev+0x136/0x4e0
[ 131.143701] ? do_writev+0x16e/0x1d0
[ 131.146977] ? do_syscall_64+0x5b/0x70
[ 131.150221] ? entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 131.153635] ? lock_downgrade+0x6e0/0x6e0
[ 131.156731] __set_page_owner+0x37/0x280
[ 131.159791] __alloc_pages_bulk+0x7fa/0xf20
[ 131.162973] __vmalloc_area_node+0x1b3/0x5e0
[ 131.166336] ? vmalloc_32+0x80/0x80
[ 131.169357] ? __get_vm_area_node+0x219/0x2f0
[ 131.172909] __vmalloc_node_range+0xac/0x150
[ 131.176086] ? netlink_sendmsg+0x4df/0xb50
[ 131.179313] vmalloc+0x62/0x80
[ 131.182431] ? netlink_sendmsg+0x4df/0xb50
[ 131.185644] netlink_sendmsg+0x4df/0xb50
[ 131.188809] ? netlink_unicast+0x5a0/0x5a0
[ 131.191886] ? perf_event_switch_output+0x1d1/0x550
[ 131.195220] ? netlink_unicast+0x5a0/0x5a0
[ 131.198281] sock_sendmsg+0xa6/0xe0
[ 131.201126] sock_write_iter+0x1fe/0x340
[ 131.204062] ? sock_sendmsg+0xe0/0xe0
[ 131.206881] do_iter_readv_writev+0x332/0x6b0
[ 131.209772] ? new_sync_write+0x5e0/0x5e0
[ 131.212544] ? iovec_from_user+0x131/0x280
[ 131.215422] do_iter_write+0x12c/0x5c0
[ 131.218167] vfs_writev+0x136/0x4e0
[ 131.220839] ? vfs_iter_write+0xb0/0xb0
[ 131.223483] ? rcu_read_unlock+0x40/0x40
[ 131.226071] ? lock_downgrade+0x6e0/0x6e0
[ 131.228626] ? lockdep_hardirqs_on_prepare+0x273/0x3e0
[ 131.231406] ? _raw_spin_unlock_irq+0x1f/0x30
[ 131.234085] ? trace_hardirqs_on+0x1c/0x160
[ 131.236772] ? finish_task_switch+0x246/0x6e0
[ 131.239545] ? __switch_to+0x54a/0x12a0
[ 131.242227] ? do_writev+0x16e/0x1d0
[ 131.244787] do_writev+0x16e/0x1d0
[ 131.247410] ? vfs_writev+0x4e0/0x4e0
[ 131.250008] ? lockdep_hardirqs_on_prepare+0x273/0x3e0
[ 131.252863] ? syscall_enter_from_user_mode+0x1d/0x50
[ 131.255647] ? trace_hardirqs_on+0x1c/0x160
[ 131.258364] do_syscall_64+0x5b/0x70
[ 131.260984] ? lockdep_hardirqs_on_prepare+0x273/0x3e0
[ 131.263719] ? do_syscall_64+0x68/0x70
[ 131.266422] ? do_syscall_64+0x68/0x70
[ 131.269023] ? do_syscall_64+0x68/0x70
[ 131.271661] ? lockdep_hardirqs_on_prepare+0x273/0x3e0
[ 131.274465] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 131.277215] RIP: 0033:0x463519
[ 131.279691] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 db 59 00 00 c3 66 2e 0f 1f 84 00 00 00 00
[ 131.286788] RSP: 002b:00007fffc28c74a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000014
[ 131.290307] RAX: ffffffffffffffda RBX: 0000000000000014 RCX: 0000000000463519
[ 131.293720] RDX: 0000000000000001 RSI: 0000000001435d80 RDI: 000000000000017e
[ 131.297238] RBP: 00007fb6964b0000 R08: 00000000ffffff12 R09: 00000000dededede
[ 131.300607] R10: 0000000000000400 R11: 0000000000000246 R12: 0000000000000002
[ 131.304009] R13: 00007fb6964b0058 R14: 000000000109a850 R15: 00007fb6964b0000
[ 131.341890] ------------[ cut here ]------------
[ 131.345319] raw_local_irq_restore() called with IRQs enabled
[ 131.349355] WARNING: CPU: 0 PID: 2928 at kernel/locking/irqflag-debug.c:10 warn_bogus_irq_restore+0x1d/0x20
[ 131.353405] Modules linked in:
[ 131.356841] CPU: 0 PID: 2928 Comm: trinity-c6 Tainted: G W 5.13.0+ #1
[ 131.360663] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 131.366561] RIP: 0010:warn_bogus_irq_restore+0x1d/0x20
[ 131.370156] Code: 24 48 c7 c7 40 a6 a5 86 e8 a9 44 b8 ff 80 3d 19 58 98 04 00 74 01 c3 48 c7 c7 c0 5d a8 86 c6 05 08 58 98 04 01 e8 cf 43 b8 ff <0f> 0b c3 44 8b 05 35 29 a3 04 55 53 65 48 8b 1c 25 00 ef 01 00 45
[ 131.378834] RSP: 0018:ffffc900034977a8 EFLAGS: 00010286
[ 131.382898] RAX: 0000000000000000 RBX: 000000000000001f RCX: 0000000000000000
[ 131.387038] RDX: 0000000000000001 RSI: 0000000000000008 RDI: fffff52000692eeb
[ 131.391207] RBP: ffff8881346af8f8 R08: 0000000000000001 R09: ffffed1073efdc94
[ 131.396053] R10: ffff88839f7ee49f R11: ffffed1073efdc93 R12: ffff88839f7f7500
[ 131.400370] R13: 000000000000001f R14: ffffea0004b54b40 R15: dffffc0000000000
[ 131.404625] FS: 000000000109a880(0000) GS:ffff88839f600000(0000) knlGS:0000000000000000
[ 131.409112] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 131.413318] CR2: 000000000109a850 CR3: 0000000149c79000 CR4: 00000000000406b0
[ 131.417799] DR0: 0000000040642000 DR1: 00007fb695fa6000 DR2: 0000000000000000
[ 131.424782] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 000000000099060a
[ 131.429461] Call Trace:
[ 131.433334] __alloc_pages_bulk+0xbb8/0xf20
[ 131.437394] __vmalloc_area_node+0x1b3/0x5e0
[ 131.443929] ? vmalloc_32+0x80/0x80
[ 131.447950] ? __get_vm_area_node+0x219/0x2f0
[ 131.452296] __vmalloc_node_range+0xac/0x150
[ 131.456569] ? netlink_sendmsg+0x4df/0xb50
[ 131.460811] vmalloc+0x62/0x80
[ 131.464882] ? netlink_sendmsg+0x4df/0xb50
[ 131.469108] netlink_sendmsg+0x4df/0xb50
[ 131.473234] ? netlink_unicast+0x5a0/0x5a0
[ 131.477236] ? perf_event_switch_output+0x1d1/0x550
[ 131.481472] ? netlink_unicast+0x5a0/0x5a0
[ 131.486124] sock_sendmsg+0xa6/0xe0
[ 131.490170] sock_write_iter+0x1fe/0x340
[ 131.494270] ? sock_sendmsg+0xe0/0xe0
[ 131.498437] do_iter_readv_writev+0x332/0x6b0
[ 131.505391] ? new_sync_write+0x5e0/0x5e0
[ 131.509677] ? iovec_from_user+0x131/0x280
[ 131.513861] do_iter_write+0x12c/0x5c0
[ 131.517953] vfs_writev+0x136/0x4e0
[ 131.522394] ? vfs_iter_write+0xb0/0xb0
[ 131.526180] ? rcu_read_unlock+0x40/0x40
[ 131.530012] ? lock_downgrade+0x6e0/0x6e0
[ 131.533748] ? lockdep_hardirqs_on_prepare+0x273/0x3e0
[ 131.538083] ? _raw_spin_unlock_irq+0x1f/0x30
[ 131.541913] ? trace_hardirqs_on+0x1c/0x160
[ 131.545624] ? finish_task_switch+0x246/0x6e0
[ 131.549389] ? __switch_to+0x54a/0x12a0
[ 131.554470] ? do_writev+0x16e/0x1d0
[ 131.558083] do_writev+0x16e/0x1d0
[ 131.561365] ? vfs_writev+0x4e0/0x4e0
[ 131.564850] ? lockdep_hardirqs_on_prepare+0x273/0x3e0
[ 131.572683] ? syscall_enter_from_user_mode+0x1d/0x50
[ 131.576333] ? trace_hardirqs_on+0x1c/0x160
[ 131.580327] do_syscall_64+0x5b/0x70
[ 131.583807] ? lockdep_hardirqs_on_prepare+0x273/0x3e0
[ 131.594627] ? do_syscall_64+0x68/0x70
[ 131.598210] ? do_syscall_64+0x68/0x70
[ 131.601861] ? do_syscall_64+0x68/0x70
[ 131.604856] ? lockdep_hardirqs_on_prepare+0x273/0x3e0
[ 131.607985] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 131.611208] RIP: 0033:0x463519
[ 131.614430] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 db 59 00 00 c3 66 2e 0f 1f 84 00 00 00 00
[ 131.621939] RSP: 002b:00007fffc28c74a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000014
[ 131.625629] RAX: ffffffffffffffda RBX: 0000000000000014 RCX: 0000000000463519
[ 131.629324] RDX: 0000000000000001 RSI: 0000000001435d80 RDI: 000000000000017e
[ 131.636748] RBP: 00007fb6964b0000 R08: 00000000ffffff12 R09: 00000000dededede
[ 131.640262] R10: 0000000000000400 R11: 0000000000000246 R12: 0000000000000002
[ 131.643810] R13: 00007fb6964b0058 R14: 000000000109a850 R15: 00007fb6964b0000
[ 131.647397] irq event stamp: 284171
[ 131.651030] hardirqs last enabled at (284181): [<ffffffff8129a291>] console_unlock+0x731/0x950
[ 131.654922] hardirqs last disabled at (284190): [<ffffffff8129a1a5>] console_unlock+0x645/0x950
[ 131.658808] softirqs last enabled at (283478): [<ffffffff86800623>] __do_softirq+0x623/0x9db
[ 131.662610] softirqs last disabled at (283079): [<ffffffff8116dfee>] irq_exit_rcu+0xce/0xf0
[ 131.669599] ---[ end trace 8eb344c762dcdfce ]---


To reproduce:

# build kernel
cd linux
cp config-5.13.0+ .config
make HOSTCC=gcc-9 CC=gcc-9 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage

git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email



---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/[email protected] Intel Corporation

Thanks,
Oliver Sang


Attachments:
(No filename) (11.16 kB)
config-5.13.0+ (190.07 kB)
job-script (4.30 kB)
dmesg.xz (21.38 kB)
trinity (2.44 kB)
Download all attachments

2021-07-13 18:21:44

by Linus Torvalds

[permalink] [raw]
Subject: Re: [mm/vmalloc] 5c1f4e690e: BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c

On Tue, Jul 13, 2021 at 7:06 AM kernel test robot <[email protected]> wrote:
>
> [ 131.014885] BUG: sleeping function called from invalid context at mm/page_alloc.c:4992

Strange. The call chain doesn't actually seem to be anything off: it's
writev -> sock_write_iter -> sock_sendmsg -> netlink_sendmsg ->
vmalloc.

All good to sleep as far as I can tell. The warning itself seems to be just

might_sleep_if(gfp_mask & __GFP_DIRECT_RECLAIM);

in prepare_alloc_pages().

I don't see what's wrong with that commit, but it does seem to be very
consistent, in that the parent doesn't have it:

> +----------------------------------------------------------------------+------------+------------+
> | | a2afc59fb2 | 5c1f4e690e |
> +----------------------------------------------------------------------+------------+------------+
> | BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c | 0 | 54 |
> +----------------------------------------------------------------------+------------+------------+

Does anybody see what the problem is there?

There's an odd report _after_ the warning:

[ 131.345319] raw_local_irq_restore() called with IRQs enabled
[ 131.366561] RIP: 0010:warn_bogus_irq_restore+0x1d/0x20
[ 131.433334] __alloc_pages_bulk+0xbb8/0xf20

but I think that's might be a result of the BUG(). Maybe. But it might
also be indicative of some context confusion - do we end up nesting?
Because the BUG() has

[ 131.036625] hardirqs last disabled at (283042):
[<ffffffff81656d71>] __alloc_pages_bulk+0xae1/0xf20

which means that the might_sleep_if() happens _after_
__alloc_pages_bulk() has disabled interrupts. That would explain it,
but the stack_depot_save() thing actually makes that call chain really
hard to read because it duplicates the addresses on the stack.

I don't see the nesting there, but that's what it kind of smells like to me.

Anybody?

Linus

2021-07-13 18:29:23

by Matthew Wilcox (Oracle)

[permalink] [raw]
Subject: Re: [mm/vmalloc] 5c1f4e690e: BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c

On Tue, Jul 13, 2021 at 11:19:29AM -0700, Linus Torvalds wrote:
> Does anybody see what the problem is there?
>
> There's an odd report _after_ the warning:
>
> [ 131.345319] raw_local_irq_restore() called with IRQs enabled
> [ 131.366561] RIP: 0010:warn_bogus_irq_restore+0x1d/0x20
> [ 131.433334] __alloc_pages_bulk+0xbb8/0xf20

That's the key -- __alloc_pages_bulk has interrupts disabled and then
page_owner allocates memory for the stack dump. Mel has a fix; I think
we're just waiting for it to hit your tree.

2021-07-13 19:55:01

by Linus Torvalds

[permalink] [raw]
Subject: Re: [mm/vmalloc] 5c1f4e690e: BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c

[ I've asked for this before, but I'll ask for it again.. ]

On Tue, Jul 13, 2021 at 7:06 AM kernel test robot <[email protected]> wrote:
>
>
> [ 131.014885] BUG: sleeping function called from invalid context at mm/page_alloc.c:4992
> [ 131.019428] in_atomic(): 0, irqs_disabled(): 1, non_block: 0, pid: 2928, name: trinity-c6
> [ 131.023996] no locks held by trinity-c6/2928.
> [ 131.027987] irq event stamp: 283042
> [ 131.031844] hardirqs last enabled at (283041): [<ffffffff8643af22>] _raw_spin_unlock_irqrestore+0x42/0x50
> [ 131.036625] hardirqs last disabled at (283042): [<ffffffff81656d71>] __alloc_pages_bulk+0xae1/0xf20
> [ 131.041305] softirqs last enabled at (281858): [<ffffffff86800623>] __do_softirq+0x623/0x9db
> [ 131.046157] softirqs last disabled at (281853): [<ffffffff8116dfee>] irq_exit_rcu+0xce/0xf0
> [ 131.050925] CPU: 0 PID: 2928 Comm: trinity-c6 Not tainted 5.13.0+ #1
> [ 131.055391] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> [ 131.060133] Call Trace:
> [ 131.064110] dump_stack+0xa5/0xe6
> [ 131.068192] ___might_sleep.cold+0x147/0x177
> [ 131.072324] __alloc_pages+0x462/0x650

Btw, can I ask the kernel test robot to do the same thing I asked
syzbot to do - namely get better backtrace annotations?

It requires debug info in the kernel (but I think DEBUG_INFO_REDUCED
is sufficient, no need for the full one that blows sizes up a lot),
but it makes things _soo_ much easier to read. Not just because of
line numbers, but particularly with inlining information.

It's easy enough to do: just run the kernel output through
"scripts/decode_stacktrace.sh".

That will also do the "Code:" line instruction disassembly, which is
less critical, since that can be done later at any time with no loss
of information, but it can be a convenience.

Linus

2021-07-13 19:59:53

by Uladzislau Rezki

[permalink] [raw]
Subject: Re: [mm/vmalloc] 5c1f4e690e: BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c

On Tue, Jul 13, 2021 at 07:26:53PM +0100, Matthew Wilcox wrote:
> On Tue, Jul 13, 2021 at 11:19:29AM -0700, Linus Torvalds wrote:
> > Does anybody see what the problem is there?
> >
> > There's an odd report _after_ the warning:
> >
> > [ 131.345319] raw_local_irq_restore() called with IRQs enabled
> > [ 131.366561] RIP: 0010:warn_bogus_irq_restore+0x1d/0x20
> > [ 131.433334] __alloc_pages_bulk+0xbb8/0xf20
>
> That's the key -- __alloc_pages_bulk has interrupts disabled and then
> page_owner allocates memory for the stack dump. Mel has a fix; I think
> we're just waiting for it to hit your tree.
>
I was thinking about how we came to the step when a sleeping check is fired
somewhere deep in the "page-bulk" allocator. If vmalloc was invoked from
non-sleepin context we would see it earlier, at least in alloc_vmap_area().

I think, the bulk allocator disables interrupts and does some sleeping
things.

Matthew, Could you please point to the fix?

--
Vlad Rezki

2021-07-13 21:56:08

by Mel Gorman

[permalink] [raw]
Subject: Re: [mm/vmalloc] 5c1f4e690e: BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c

On Tue, Jul 13, 2021 at 11:19:29AM -0700, Linus Torvalds wrote:
> On Tue, Jul 13, 2021 at 7:06 AM kernel test robot <[email protected]> wrote:
> >
> > [ 131.014885] BUG: sleeping function called from invalid context at mm/page_alloc.c:4992
>
> Strange. The call chain doesn't actually seem to be anything off: it's
> writev -> sock_write_iter -> sock_sendmsg -> netlink_sendmsg ->
> vmalloc.
>
> All good to sleep as far as I can tell. The warning itself seems to be just
>
> might_sleep_if(gfp_mask & __GFP_DIRECT_RECLAIM);
>
> in prepare_alloc_pages().
>
> I don't see what's wrong with that commit, but it does seem to be very
> consistent, in that the parent doesn't have it:
>

It's almost certainly going to be fixed by
https://lore.kernel.org/r/[email protected]
whenever it hits your tree as part of this series
https://lore.kernel.org/lkml/[email protected]/.
It should make its way through Andrew's tree before RC2 but if he is busy
I'll create a git pull request.

> which means that the might_sleep_if() happens _after_
> __alloc_pages_bulk() has disabled interrupts. That would explain it,
> but the stack_depot_save() thing actually makes that call chain really
> hard to read because it duplicates the addresses on the stack.
>
> I don't see the nesting there, but that's what it kind of smells like to me.
>
> Anybody?
>

The problem is that PAGE_OWNER can recurse allocate from bulk allocation
context to store the caller stack. When I wrote the patch, I missed that
prep_new_page can allocate if PAGE_OWNER is active. The most relevant
part of the trace is

[ 131.092667] stack_depot_save+0x390/0x4c0

--
Mel Gorman
SUSE Labs

2021-07-14 08:51:03

by Chen, Rong A

[permalink] [raw]
Subject: Re: [LKP] Re: [mm/vmalloc] 5c1f4e690e: BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c



On 7/14/2021 3:52 AM, Linus Torvalds wrote:
> [ I've asked for this before, but I'll ask for it again.. ]
>
> On Tue, Jul 13, 2021 at 7:06 AM kernel test robot <[email protected]> wrote:
>>
>>
>> [ 131.014885] BUG: sleeping function called from invalid context at mm/page_alloc.c:4992
>> [ 131.019428] in_atomic(): 0, irqs_disabled(): 1, non_block: 0, pid: 2928, name: trinity-c6
>> [ 131.023996] no locks held by trinity-c6/2928.
>> [ 131.027987] irq event stamp: 283042
>> [ 131.031844] hardirqs last enabled at (283041): [<ffffffff8643af22>] _raw_spin_unlock_irqrestore+0x42/0x50
>> [ 131.036625] hardirqs last disabled at (283042): [<ffffffff81656d71>] __alloc_pages_bulk+0xae1/0xf20
>> [ 131.041305] softirqs last enabled at (281858): [<ffffffff86800623>] __do_softirq+0x623/0x9db
>> [ 131.046157] softirqs last disabled at (281853): [<ffffffff8116dfee>] irq_exit_rcu+0xce/0xf0
>> [ 131.050925] CPU: 0 PID: 2928 Comm: trinity-c6 Not tainted 5.13.0+ #1
>> [ 131.055391] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
>> [ 131.060133] Call Trace:
>> [ 131.064110] dump_stack+0xa5/0xe6
>> [ 131.068192] ___might_sleep.cold+0x147/0x177
>> [ 131.072324] __alloc_pages+0x462/0x650
>
> Btw, can I ask the kernel test robot to do the same thing I asked
> syzbot to do - namely get better backtrace annotations?

Hi Linus,

Sorry for this, we enabled COMPILE_TEST for randconfig which is conflict
with DEBUG_INFO, then "scripts/decode_stacktrace.sh" was ignored in this
case, we'll fix it asap and have a double check next time.

Best Regards,
Rong Chen


>
> It requires debug info in the kernel (but I think DEBUG_INFO_REDUCED
> is sufficient, no need for the full one that blows sizes up a lot),
> but it makes things _soo_ much easier to read. Not just because of
> line numbers, but particularly with inlining information.
>
> It's easy enough to do: just run the kernel output through
> "scripts/decode_stacktrace.sh".
>
> That will also do the "Code:" line instruction disassembly, which is
> less critical, since that can be done later at any time with no loss
> of information, but it can be a convenience.
>
> Linus
> _______________________________________________
> LKP mailing list -- [email protected]
> To unsubscribe send an email to [email protected]
>