@@ -2871,7 +2871,8 @@ __rmqueue(struct zone *zone, unsigned int order,
int migratetype,
goto retry;
}
- trace_mm_page_alloc_zone_locked(page, order, migratetype);
+ if (page)
+ trace_mm_page_alloc_zone_locked(page, order, migratetype);
return page;
}
If I apply this patch on top of 5.10.11, the issue disappears.
I can't say I understand the connection here.
It's worth mentioning that the issue doesn't reproduce with
UNWINDER_FRAME_POINTER rather than UNWINDER_ORC. This fact makes me
think that ORC is to blame here somehow, but it's beyond my
understanding.
Here's how I replicate the issue in qemu running Debian Buster:
# /tmp is tmpfs in our case
$ qemu-img create -f qcow2 /tmp/nvme-$USER.img 10G
$ sudo qemu-system-x86_64 -smp 1 -m 3G -enable-kvm -cpu host -kernel
~/vmlinuz -initrd ~/initrd.img -nographic -device e1000 -device
nvme,drive=nvme0,serial=deadbeaf1,num_queues=8 -drive
file=/tmp/nvme-$USER.img,if=none,id=nvme0 -append 'console=ttyS0
kasan_multi_shot'
Inside of the VM:
root@localhost:~# echo -e '[Match]\nName=enp*\n[Network]\nDHCP=yes' >
/etc/systemd/network/00-dhcp.network
root@localhost:~# systemctl restart systemd-networkd
root@localhost:~# apt-get update
root@localhost:~# apt-get install -y --no-install-recommends cryptsetup
root@localhost:~# echo potato > keyfile
root@localhost:~# chmod 0400 keyfile
root@localhost:~# cryptsetup -q luksFormat /dev/nvme0n1 keyfile
root@localhost:~# cryptsetup open --type luks --key-file keyfile
--disable-keyring /dev/nvme0n1 luks-nvme0n1
root@localhost:~# dmsetup table /dev/mapper/luks-nvme0n1 | sed 's/$/ 2
no_read_workqueue no_write_workqueue/' | dmsetup reload
/dev/mapper/luks-nvme0n1
root@localhost:~# dmsetup suspend /dev/mapper/luks-nvme0n1 && dmsetup
resume /dev/mapper/luks-nvme0n1
root@localhost:~# mkfs.xfs -f /dev/mapper/luks-nvme0n1
root@localhost:~# mount /dev/mapper/luks-nvme0n1 /mnt
The workload that triggers the KASAN complaint is the following:
root@localhost:~# while true; do rm -f /mnt/random.data.target && dd
if=/dev/zero of=/mnt/random.data bs=10M count=400 status=progress &&
mv /mnt/random.data /mnt/random.data.target; sleep 1; done
It might take a few iterations to trigger.
Note that dmcrypt setup in our case depends on Ignat's patches, which
are included in 5.10.11 and 5.11-rc5, so during bisection between
5.11-rc3 and 5.11-rc4 they needed to be reapplied.
I'm going to ask for a backport of the "fix" to stable, but it feels
like there's a bigger issue here.
Hello again and the first hello for new people in CC as I have an update,
(Please let me know if I should get the list of people to CC not from
get_maintainers.pl, since it gave me a lot of people and it doesn't
feel right.)
We've seen the issue even after backporting ce8f86ee94fa, this time
much later in uptime, outside of dm-crypt and without a reliable
reproduction.
I noticed that the bug doesn't reproduce on Linux v5.9, so I went
ahead and bisected v5.9..v5.10-rc1 to see where it all started (with
dm-crypt reproduction).
Since there's a ton of merges and regular bisect gave me questionable
results, I had to resort to --first-parent first, which pointed at
dd502a81077a:
$ git bisect log
git bisect start '--first-parent'
# bad: [3650b228f83adda7e5ee532e2b90429c03f7b9ec] Linux 5.10-rc1
git bisect bad 3650b228f83adda7e5ee532e2b90429c03f7b9ec
# good: [bbf5c979011a099af5dc76498918ed7df445635b] Linux 5.9
git bisect good bbf5c979011a099af5dc76498918ed7df445635b
# bad: [578a7155c5a1894a789d4ece181abf9d25dc6b0d] Merge tag
'linux-kselftest-kunit-fixes-5.10-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/shuah/linux-kselftest
git bisect bad 578a7155c5a1894a789d4ece181abf9d25dc6b0d
# bad: [3ad11d7ac8872b1c8da54494721fad8907ee41f7] Merge tag
'block-5.10-2020-10-12' of git://git.kernel.dk/linux-block
git bisect bad 3ad11d7ac8872b1c8da54494721fad8907ee41f7
# bad: [b85cac574592b843c4be93c83303feeee0c4dc25] Merge tag
'x86-kaslr-2020-10-12' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad b85cac574592b843c4be93c83303feeee0c4dc25
# good: [64743e652cea9d6df4264caaa1d7f95273024afb] Merge tag
'x86_cache_for_v5.10' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good 64743e652cea9d6df4264caaa1d7f95273024afb
# good: [edaa5ddf3833669a25654d42c0fb653dfdd906df] Merge tag
'sched-core-2020-10-12' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good edaa5ddf3833669a25654d42c0fb653dfdd906df
# good: [34eb62d868d729e9a252aa497277081fb652eeed] Merge tag
'core-build-2020-10-12' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good 34eb62d868d729e9a252aa497277081fb652eeed
# bad: [3bff6112c80cecb76af5fe485506f96e8adb6122] Merge tag
'perf-core-2020-10-12' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad 3bff6112c80cecb76af5fe485506f96e8adb6122
# bad: [dd502a81077a5f3b3e19fa9a1accffdcab5ad5bc] Merge tag
'core-static_call-2020-10-12' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad dd502a81077a5f3b3e19fa9a1accffdcab5ad5bc
# first bad commit: [dd502a81077a5f3b3e19fa9a1accffdcab5ad5bc] Merge
tag 'core-static_call-2020-10-12' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
Since core-static_call-2020-10-12 tag is based on top of 5.9-rc3, I
rebased it on v5.9 and repeated the bisect between that and v5.9:
$ git checkout core-static_call-2020-10-12
$ git rebase v5.9
$ git checkout -b ivan/static_call-2020-10-12-rebase-on-v5.9
$ git bisect log
git bisect start
# bad: [6c2fc089268777994dd82ce7c60263f3a71ed0b4] static_call: Fix
return type of static_call_init
git bisect bad 6c2fc089268777994dd82ce7c60263f3a71ed0b4
# good: [bbf5c979011a099af5dc76498918ed7df445635b] Linux 5.9
git bisect good bbf5c979011a099af5dc76498918ed7df445635b
# good: [580b6f7a0af7823277b3ec9aeb2ff48596c10662] x86/static_call:
Add inline static call implementation for x86-64
git bisect good 580b6f7a0af7823277b3ec9aeb2ff48596c10662
# good: [574169ad2d8ce8a80d2798e502d289f6741d8096] static_call: Add
some validation
git bisect good 574169ad2d8ce8a80d2798e502d289f6741d8096
# bad: [4c9c8903fcfb8fca9ab84a8906ee23c998086549] x86/perf,
static_call: Optimize x86_pmu methods
git bisect bad 4c9c8903fcfb8fca9ab84a8906ee23c998086549
# bad: [edfd9b7838ba5e47f19ad8466d0565aba5c59bf0] tracepoint: Optimize
using static_call()
git bisect bad edfd9b7838ba5e47f19ad8466d0565aba5c59bf0
# good: [a5ea9249fde1027124f7ae42d6ca17d53fcb3df0] static_call: Allow early init
git bisect good a5ea9249fde1027124f7ae42d6ca17d53fcb3df0
# first bad commit: [edfd9b7838ba5e47f19ad8466d0565aba5c59bf0]
tracepoint: Optimize using static_call()
edfd9b7838ba5e47f19ad8466d0565aba5c59bf0 is the first bad commit
commit edfd9b7838ba5e47f19ad8466d0565aba5c59bf0
Author: Steven Rostedt (VMware) [off-list ref]
Date: Tue Aug 18 15:57:52 2020 +0200
tracepoint: Optimize using static_call()
Currently the tracepoint site will iterate a vector and issue indirect
calls to however many handlers are registered (ie. the vector is
long).
Using static_call() it is possible to optimize this for the common
case of only having a single handler registered. In this case the
static_call() can directly call this handler. Otherwise, if the vector
is longer than 1, call a function that iterates the whole vector like
the current code.
[peterz: updated to new interface]
Signed-off-by: Steven Rostedt (VMware) [off-list ref]
Signed-off-by: Peter Zijlstra (Intel) [off-list ref]
Signed-off-by: Ingo Molnar [off-list ref]
Cc: Linus Torvalds [off-list ref]
Link: https://lore.kernel.org/r/20200818135805.279421092@infradead.org
include/linux/tracepoint-defs.h | 5 +++
include/linux/tracepoint.h | 86 +++++++++++++++++++++++++++++------------
include/trace/define_trace.h | 14 +++----
kernel/tracepoint.c | 25 ++++++++++--
4 files changed, 94 insertions(+), 36 deletions(-)
Upstream commit hash is d25e37d89dd2:
* https://github.com/torvalds/linux/commit/d25e37d89dd2
I double checked and its parent (a945c8345ec0) works fine.
Note that the "fix" for 5.10.11 was also tracepoint related:
* https://github.com/torvalds/linux/commit/ce8f86ee94fa
Let me know how I can help get this fixed or debugged further. I'm
happy to try patches.
I've tried it on top of core-static_call-2020-10-12 tag rebased on top
of v5.9 (to make it reproducible), and the patch did not help. Do I
need to apply the whole series or something else?
I've tried it on top of core-static_call-2020-10-12 tag rebased on top
of v5.9 (to make it reproducible), and the patch did not help. Do I
need to apply the whole series or something else?
Can you recreate with this patch, and add "unwind_debug" to the cmdline?
It will spit out a bunch of stack data.
From: Josh Poimboeuf <redacted>
Subject: [PATCH] Subject: [PATCH] x86/unwind: Add 'unwind_debug' cmdline
option
Sometimes the one-line ORC unwinder warnings aren't very helpful. Take
the existing frame pointer unwind_dump() and make it useful for all
unwinders.
I don't want to be too aggressive about enabling the dumps, so for now
they're only enabled with the use of a new 'unwind_debug' cmdline
option. When enabled, it will dump the full contents of the stack when
an error condition is encountered, or when dump_stack() is called.
Signed-off-by: Josh Poimboeuf <redacted>
---
.../admin-guide/kernel-parameters.txt | 6 +++
arch/x86/include/asm/unwind.h | 3 ++
arch/x86/kernel/dumpstack.c | 39 ++++++++++++++
arch/x86/kernel/unwind_frame.c | 51 +++----------------
arch/x86/kernel/unwind_orc.c | 5 +-
5 files changed, 58 insertions(+), 46 deletions(-)
@@ -244,7 +202,6 @@ static bool update_stack_state(struct unwind_state *state,addr,addr_p);}-/* Save the original stack pointer for unwind_dump(): */if(!state->orig_sp)state->orig_sp=frame;
@@ -346,13 +303,17 @@ bool unwind_next_frame(struct unwind_state *state)"WARNING: kernel stack regs at %p in %s:%d has bad 'bp' value %p\n",state->regs,state->task->comm,state->task->pid,next_bp);-unwind_dump(state);++if(unwind_debug)+unwind_dump(state);}else{printk_deferred_once(KERN_WARNING"WARNING: kernel stack frame pointer at %p in %s:%d has bad value %p\n",state->bp,state->task->comm,state->task->pid,next_bp);-unwind_dump(state);++if(unwind_debug)+unwind_dump(state);}the_end:state->stack_info.type=STACK_TYPE_UNKNOWN;
I've tried it on top of core-static_call-2020-10-12 tag rebased on top
of v5.9 (to make it reproducible), and the patch did not help. Do I
need to apply the whole series or something else?
Can you recreate with this patch, and add "unwind_debug" to the cmdline?
It will spit out a bunch of stack data.
Here's the three I'm building:
* https://github.com/bobrik/linux/tree/ivan/static-call-5.9
It contains:
* v5.9 tag as the base
* static_call-2020-10-12 tag
* dm-crypt patches to reproduce the issue with KASAN
* x86/unwind: Add 'unwind_debug' cmdline option
* tracepoint: Fix race between tracing and removing tracepoint
The very same issue can be reproduced on 5.10.11 with no patches,
but I'm going with 5.9, since it boils down to static call changes.
Here's the decoded stack from the kernel with unwind debug enabled:
* https://gist.github.com/bobrik/ed052ac0ae44c880f3170299ad4af56b
See my first email for the exact commands that trigger this.
I've tried it on top of core-static_call-2020-10-12 tag rebased on top
of v5.9 (to make it reproducible), and the patch did not help. Do I
need to apply the whole series or something else?
Can you recreate with this patch, and add "unwind_debug" to the cmdline?
It will spit out a bunch of stack data.
Here's the three I'm building:
* https://github.com/bobrik/linux/tree/ivan/static-call-5.9
It contains:
* v5.9 tag as the base
* static_call-2020-10-12 tag
* dm-crypt patches to reproduce the issue with KASAN
* x86/unwind: Add 'unwind_debug' cmdline option
* tracepoint: Fix race between tracing and removing tracepoint
The very same issue can be reproduced on 5.10.11 with no patches,
but I'm going with 5.9, since it boils down to static call changes.
Here's the decoded stack from the kernel with unwind debug enabled:
* https://gist.github.com/bobrik/ed052ac0ae44c880f3170299ad4af56b
See my first email for the exact commands that trigger this.
Thanks. Do you happen to have the original dmesg, before running it
through the post-processing script?
I assume you're using decode_stacktrace.sh? It could use some
improvement, it's stripping the function offset.
Also spaces are getting inserted in odd places, messing the alignment.
[ 137.291837][ C0] ffff88809c409858: d7c4f3ce817a1700 (0xd7c4f3ce817a1700)
[ 137.291837][ C0] ffff88809c409860: 0000000000000000 (0x0)
[ 137.291839][ C0] ffff88809c409868: 00000000ffffffff (0xffffffff)
[ 137.291841][ C0] ffff88809c409870: ffffffffa4f01a52 unwind_next_frame (arch/x86/kernel/unwind_orc.c:380 arch/x86/kernel/unwind_orc.c:553)
[ 137.291843][ C0] ffff88809c409878: ffffffffa4f01a52 unwind_next_frame (arch/x86/kernel/unwind_orc.c:380 arch/x86/kernel/unwind_orc.c:553)
[ 137.291844][ C0] ffff88809c409880: ffff88809c409ac8 (0xffff88809c409ac8)
[ 137.291845][ C0] ffff88809c409888: 0000000000000086 (0x86)
--
Josh
I've tried it on top of core-static_call-2020-10-12 tag rebased on top
of v5.9 (to make it reproducible), and the patch did not help. Do I
need to apply the whole series or something else?
Can you recreate with this patch, and add "unwind_debug" to the cmdline?
It will spit out a bunch of stack data.
Here's the three I'm building:
* https://github.com/bobrik/linux/tree/ivan/static-call-5.9
It contains:
* v5.9 tag as the base
* static_call-2020-10-12 tag
* dm-crypt patches to reproduce the issue with KASAN
* x86/unwind: Add 'unwind_debug' cmdline option
* tracepoint: Fix race between tracing and removing tracepoint
The very same issue can be reproduced on 5.10.11 with no patches,
but I'm going with 5.9, since it boils down to static call changes.
Here's the decoded stack from the kernel with unwind debug enabled:
* https://gist.github.com/bobrik/ed052ac0ae44c880f3170299ad4af56b
See my first email for the exact commands that trigger this.
Thanks. Do you happen to have the original dmesg, before running it
through the post-processing script?
On Wed, Feb 03, 2021 at 03:30:35PM -0800, Ivan Babrou wrote:
quoted
quoted
quoted
Can you recreate with this patch, and add "unwind_debug" to the cmdline?
It will spit out a bunch of stack data.
Here's the three I'm building:
* https://github.com/bobrik/linux/tree/ivan/static-call-5.9
It contains:
* v5.9 tag as the base
* static_call-2020-10-12 tag
* dm-crypt patches to reproduce the issue with KASAN
* x86/unwind: Add 'unwind_debug' cmdline option
* tracepoint: Fix race between tracing and removing tracepoint
The very same issue can be reproduced on 5.10.11 with no patches,
but I'm going with 5.9, since it boils down to static call changes.
Here's the decoded stack from the kernel with unwind debug enabled:
* https://gist.github.com/bobrik/ed052ac0ae44c880f3170299ad4af56b
See my first email for the exact commands that trigger this.
Thanks. Do you happen to have the original dmesg, before running it
through the post-processing script?
It appears the unwinder is getting lost in crypto code. No idea what
this has to do with static calls though. Or maybe you're seeing
multiple issues.
Does this fix it?
@@ -237,8 +237,8 @@ define_reg j %j.noaltmacro.endm-# need to push 4 registers into stack to maintain-STACK_OFFSET=8*4+# need to push 5 registers into stack to maintain+STACK_OFFSET=8*5TMP1=16*0# Temporary storage for AADTMP2=16*1# Temporary storage for AES State 2 (State 1 is stored in an XMM register)
@@ -257,6 +257,8 @@ VARIABLE_OFFSET = 16*8.macroFUNC_SAVE#the number of pushes must equal STACK_OFFSET+push%rbp+mov%rsp, %rbppush%r12push%r13push%r14
@@ -271,12 +273,14 @@ VARIABLE_OFFSET = 16*8.endm.macroFUNC_RESTORE+add$VARIABLE_OFFSET,%rspmov%r14, %rsppop%r15pop%r14pop%r13pop%r12+pop%rbp.endm# Encryption of a single block
From: Ivan Babrou <hidden> Date: 2021-02-04 00:54:10
On Wed, Feb 3, 2021 at 4:17 PM Josh Poimboeuf [off-list ref] wrote:
On Wed, Feb 03, 2021 at 03:30:35PM -0800, Ivan Babrou wrote:
quoted
quoted
quoted
quoted
Can you recreate with this patch, and add "unwind_debug" to the cmdline?
It will spit out a bunch of stack data.
Here's the three I'm building:
* https://github.com/bobrik/linux/tree/ivan/static-call-5.9
It contains:
* v5.9 tag as the base
* static_call-2020-10-12 tag
* dm-crypt patches to reproduce the issue with KASAN
* x86/unwind: Add 'unwind_debug' cmdline option
* tracepoint: Fix race between tracing and removing tracepoint
The very same issue can be reproduced on 5.10.11 with no patches,
but I'm going with 5.9, since it boils down to static call changes.
Here's the decoded stack from the kernel with unwind debug enabled:
* https://gist.github.com/bobrik/ed052ac0ae44c880f3170299ad4af56b
See my first email for the exact commands that trigger this.
Thanks. Do you happen to have the original dmesg, before running it
through the post-processing script?
It appears the unwinder is getting lost in crypto code. No idea what
this has to do with static calls though. Or maybe you're seeing
multiple issues.
Does this fix it?
It does for the dm-crypt case! But so does the following commit in
5.11 (and 5.10.12):
* https://github.com/torvalds/linux/commit/ce8f86ee94?w=1
The reason I stuck to dm-crypt reproduction is that it reproduces reliably.
We also have the following stack that doesn't touch any crypto:
* https://gist.github.com/bobrik/40e2559add2f0b26ae39da30dc451f1e
I cannot reproduce this one, and it took 2 days of uptime for it to
happen. Is there anything I can do to help diagnose it?
My goal is to enable multishot KASAN in our pre-production
environment, but currently it sometimes starves TX queues on the NIC
due to multiple reports in a row in an interrupt about
unwind_next_frame, which disables network interface, which is not
something we can tolerate.
From: Steven Rostedt <rostedt@goodmis.org> Date: 2021-02-04 02:45:55
On Tue, 2 Feb 2021 19:09:44 -0800
Ivan Babrou [off-list ref] wrote:
On Thu, Jan 28, 2021 at 7:35 PM Ivan Babrou [off-list ref] wrote:
quoted
Hello,
We've noticed the following regression in Linux 5.10 branch:
[ 128.367231][ C0]
==================================================================
[ 128.368523][ C0] BUG: KASAN: stack-out-of-bounds in
unwind_next_frame (arch/x86/kernel/unwind_orc.c:371
The bug is a stack-out-of-bounds error in unwind_orc.c, right?
Why do we have an RIP in skcipher_walk_next, if its the unwinder that
had a bug? Or are they related?
Or did skcipher_walk_next trigger something in KASAN which did a stack
walk via the unwinder, and that caused another issue?
Looking at the unwinder code in question, we have:
static bool deref_stack_regs(struct unwind_state *state, unsigned long addr,
unsigned long *ip, unsigned long *sp)
{
struct pt_regs *regs = (struct pt_regs *)addr;
/* x86-32 support will be more complicated due to the ®s->sp hack */
BUILD_BUG_ON(IS_ENABLED(CONFIG_X86_32));
if (!stack_access_ok(state, addr, sizeof(struct pt_regs)))
return false;
*ip = regs->ip;
*sp = regs->sp; <- pointer to here
return true;
}
and the caller of the above static function:
case UNWIND_HINT_TYPE_REGS:
if (!deref_stack_regs(state, sp, &state->ip, &state->sp)) {
orc_warn_current("can't access registers at %pB\n",
(void *)orig_ip);
goto err;
}
Could it possibly be that there's some magic canary on the stack that
causes KASAN to trigger if you read it? For example, there's this in
the stack tracer:
kernel/trace/trace_stack.c: check_stack()
while (i < stack_trace_nr_entries) {
int found = 0;
stack_trace_index[x] = this_size;
p = start;
for (; p < top && i < stack_trace_nr_entries; p++) {
/*
* The READ_ONCE_NOCHECK is used to let KASAN know that
* this is not a stack-out-of-bounds error.
*/
if ((READ_ONCE_NOCHECK(*p)) == stack_dump_trace[i]) {
stack_dump_trace[x] = stack_dump_trace[i++];
this_size = stack_trace_index[x++] =
(top - p) * sizeof(unsigned long);
found = 1;
That is because I read the entire stack frame looking for values, and I
know where the top of the stack is, and will not go past it. But it too
triggered a stack-out-of-bounds error, which required the above
READ_ONCE_NOCHECK() to quiet KASAN. Not to mention there's already some
READ_ONCE_NOCHECK() calls in the unwinder. Maybe this too is required?
Would this work?
Why do we have an RIP in skcipher_walk_next, if its the unwinder that
had a bug? Or are they related?
Or did skcipher_walk_next trigger something in KASAN which did a stack
walk via the unwinder, and that caused another issue?
It was interrupted by an IRQ, which then called kfree(), which then
called kasan_save_stack(), which then called the unwinder, which then
read "out-of-bounds" between stack frames.
In this case it was because of some crypto code missing ORC annotations.
Looking at the unwinder code in question, we have:
static bool deref_stack_regs(struct unwind_state *state, unsigned long addr,
unsigned long *ip, unsigned long *sp)
{
struct pt_regs *regs = (struct pt_regs *)addr;
/* x86-32 support will be more complicated due to the ®s->sp hack */
BUILD_BUG_ON(IS_ENABLED(CONFIG_X86_32));
if (!stack_access_ok(state, addr, sizeof(struct pt_regs)))
return false;
*ip = regs->ip;
*sp = regs->sp; <- pointer to here
return true;
}
and the caller of the above static function:
case UNWIND_HINT_TYPE_REGS:
if (!deref_stack_regs(state, sp, &state->ip, &state->sp)) {
orc_warn_current("can't access registers at %pB\n",
(void *)orig_ip);
goto err;
}
Could it possibly be that there's some magic canary on the stack that
causes KASAN to trigger if you read it?
Right, the unwinder isn't allowed to read between stack frames.
In fact, you read my mind, I was looking at the other warning in network
code:
[160676.598929][ C4] asm_common_interrupt+0x1e/0x40
[160676.608966][ C4] RIP: 0010:0xffffffffc17d814c
[160676.618812][ C4] Code: 8b 4c 24 40 4c 8b 44 24 48 48 8b 7c 24 70 48 8b 74 24 68 48 8b 54 24 60 48 8b 4c 24 58 48 8b 44 24 50 48 81 c4 a8 00 00 00 9d <c3> 20 27 af 8f ff ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00
[160676.649371][ C4] RSP: 0018:ffff8893dfd4f620 EFLAGS: 00000282
[160676.661073][ C4] RAX: 0000000000000000 RBX: ffff8881be9c9c80 RCX: 0000000000000000
[160676.674788][ C4] RDX: dffffc0000000000 RSI: 000000000000000b RDI: ffff8881be9c9c80
[160676.688508][ C4] RBP: ffff8881be9c9ce0 R08: 0000000000000000 R09: ffff8881908c4c97
[160676.702249][ C4] R10: ffffed1032118992 R11: ffff88818a4ce68c R12: ffff8881be9c9eea
[160676.716000][ C4] R13: ffff8881be9c9c92 R14: ffff8880063ba5ac R15: ffff8880063ba5a8
[160676.729895][ C4] ? tcp_set_state+0x5/0x620
[160676.740426][ C4] ? tcp_fin+0xeb/0x5a0
[160676.750287][ C4] ? tcp_data_queue+0x1e78/0x4ce0
[160676.761089][ C4] ? tcp_urg+0x76/0xc50
This line gives a big clue:
[160676.608966][ C4] RIP: 0010:0xffffffffc17d814c
That address, without a function name, most likely means that it was
running in some generated code (mostly likely BPF) when it got
interrupted.
Right now, the ORC unwinder tries to fall back to frame pointers when it
encounters generated code:
orc = orc_find(state->signal ? state->ip : state->ip - 1);
if (!orc)
/*
* As a fallback, try to assume this code uses a frame pointer.
* This is useful for generated code, like BPF, which ORC
* doesn't know about. This is just a guess, so the rest of
* the unwind is no longer considered reliable.
*/
orc = &orc_fp_entry;
state->error = true;
}
Because the ORC unwinder is guessing from that point onward, it's
possible for it to read the KASAN stack redzone, if the generated code
hasn't set up frame pointers. So the best fix may be for the unwinder
to just always bypass KASAN when reading the stack.
The unwinder has a mechanism for detecting and warning about
out-of-bounds, and KASAN is short-circuiting that.
This should hopefully get rid of *all* the KASAN unwinder warnings, both
crypto and networking.
From: Ivan Babrou <hidden> Date: 2021-02-04 18:58:40
On Wed, Feb 3, 2021 at 7:10 PM Josh Poimboeuf [off-list ref] wrote:
This line gives a big clue:
[160676.608966][ C4] RIP: 0010:0xffffffffc17d814c
That address, without a function name, most likely means that it was
running in some generated code (mostly likely BPF) when it got
interrupted.
We do have eBPF/XDP in our environment.
Right now, the ORC unwinder tries to fall back to frame pointers when it
encounters generated code:
orc = orc_find(state->signal ? state->ip : state->ip - 1);
if (!orc)
/*
* As a fallback, try to assume this code uses a frame pointer.
* This is useful for generated code, like BPF, which ORC
* doesn't know about. This is just a guess, so the rest of
* the unwind is no longer considered reliable.
*/
orc = &orc_fp_entry;
state->error = true;
}
Because the ORC unwinder is guessing from that point onward, it's
possible for it to read the KASAN stack redzone, if the generated code
hasn't set up frame pointers. So the best fix may be for the unwinder
to just always bypass KASAN when reading the stack.
The unwinder has a mechanism for detecting and warning about
out-of-bounds, and KASAN is short-circuiting that.
This should hopefully get rid of *all* the KASAN unwinder warnings, both
crypto and networking.
It definitely worked on my dm-crypt case, and I've tried it without
your previous AVX related patch. I will apply it to our tree and
deploy to the staging KASAN environment to see how it fares with
respect to networking stacks. Feel free to ping me if I don't get back
to you with the results on Monday.
Thanks for looking into this!
From: Ivan Babrou <hidden> Date: 2021-02-04 19:58:57
On Wed, Feb 3, 2021 at 4:17 PM Josh Poimboeuf [off-list ref] wrote:
quoted hunk
On Wed, Feb 03, 2021 at 03:30:35PM -0800, Ivan Babrou wrote:
quoted
quoted
quoted
quoted
Can you recreate with this patch, and add "unwind_debug" to the cmdline?
It will spit out a bunch of stack data.
Here's the three I'm building:
* https://github.com/bobrik/linux/tree/ivan/static-call-5.9
It contains:
* v5.9 tag as the base
* static_call-2020-10-12 tag
* dm-crypt patches to reproduce the issue with KASAN
* x86/unwind: Add 'unwind_debug' cmdline option
* tracepoint: Fix race between tracing and removing tracepoint
The very same issue can be reproduced on 5.10.11 with no patches,
but I'm going with 5.9, since it boils down to static call changes.
Here's the decoded stack from the kernel with unwind debug enabled:
* https://gist.github.com/bobrik/ed052ac0ae44c880f3170299ad4af56b
See my first email for the exact commands that trigger this.
Thanks. Do you happen to have the original dmesg, before running it
through the post-processing script?
It appears the unwinder is getting lost in crypto code. No idea what
this has to do with static calls though. Or maybe you're seeing
multiple issues.
Does this fix it?
@@ -237,8 +237,8 @@ define_reg j %j.noaltmacro.endm-# need to push 4 registers into stack to maintain-STACK_OFFSET=8*4+# need to push 5 registers into stack to maintain+STACK_OFFSET=8*5TMP1=16*0# Temporary storage for AADTMP2=16*1# Temporary storage for AES State 2 (State 1 is stored in an XMM register)
@@ -257,6 +257,8 @@ VARIABLE_OFFSET = 16*8.macroFUNC_SAVE#the number of pushes must equal STACK_OFFSET+push%rbp+mov%rsp, %rbppush%r12push%r13push%r14
@@ -271,12 +273,14 @@ VARIABLE_OFFSET = 16*8.endm.macroFUNC_RESTORE+add$VARIABLE_OFFSET,%rspmov%r14, %rsppop%r15pop%r14pop%r13pop%r12+pop%rbp.endm# Encryption of a single block
This patch seems to fix the following warning:
[ 147.995699][ C0] WARNING: stack going in the wrong direction? at
glue_xts_req_128bit+0x21f/0x6f0 [glue_helper]
Or at least I cannot see it anymore when combined with your other
patch, not sure if it did the trick by itself.
This sounds like a good reason to send them both.
On Thu, Feb 04, 2021 at 11:51:44AM -0800, Ivan Babrou wrote:
quoted
.macro FUNC_SAVE
#the number of pushes must equal STACK_OFFSET
+ push %rbp
+ mov %rsp, %rbp
push %r12
push %r13
push %r14
@@ -271,12 +273,14 @@ VARIABLE_OFFSET = 16*8 .endm .macro FUNC_RESTORE+ add $VARIABLE_OFFSET, %rsp mov %r14, %rsp pop %r15 pop %r14 pop %r13 pop %r12+ pop %rbp .endm # Encryption of a single block
This patch seems to fix the following warning:
[ 147.995699][ C0] WARNING: stack going in the wrong direction? at
glue_xts_req_128bit+0x21f/0x6f0 [glue_helper]
Or at least I cannot see it anymore when combined with your other
patch, not sure if it did the trick by itself.
This sounds like a good reason to send them both.
Ok, that's what I expected.
The other patch fixed the unwinder failure mode to be the above
(harmless) unwinder warning, instead of a disruptive KASAN failure.
This patch fixes the specific underlying crypto unwinding metadata
issue.
I'll definitely be sending both fixes. The improved failure mode patch
will come first because it's more urgent and lower risk.
--
Josh