linux-stable/arch/arm/lib/backtrace-clang.S
Chris Down 3370155737 printk: Userspace format indexing support
We have a number of systems industry-wide that have a subset of their
functionality that works as follows:

1. Receive a message from local kmsg, serial console, or netconsole;
2. Apply a set of rules to classify the message;
3. Do something based on this classification (like scheduling a
   remediation for the machine), rinse, and repeat.

As a couple of examples of places we have this implemented just inside
Facebook, although this isn't a Facebook-specific problem, we have this
inside our netconsole processing (for alarm classification), and as part
of our machine health checking. We use these messages to determine
fairly important metrics around production health, and it's important
that we get them right.

While for some kinds of issues we have counters, tracepoints, or metrics
with a stable interface which can reliably indicate the issue, in order
to react to production issues quickly we need to work with the interface
which most kernel developers naturally use when developing: printk.

Most production issues come from unexpected phenomena, and as such
usually the code in question doesn't have easily usable tracepoints or
other counters available for the specific problem being mitigated. We
have a number of lines of monitoring defence against problems in
production (host metrics, process metrics, service metrics, etc), and
where it's not feasible to reliably monitor at another level, this kind
of pragmatic netconsole monitoring is essential.

As one would expect, monitoring using printk is rather brittle for a
number of reasons -- most notably that the message might disappear
entirely in a new version of the kernel, or that the message may change
in some way that the regex or other classification methods start to
silently fail.

One factor that makes this even harder is that, under normal operation,
many of these messages are never expected to be hit. For example, there
may be a rare hardware bug which one wants to detect if it was to ever
happen again, but its recurrence is not likely or anticipated. This
precludes using something like checking whether the printk in question
was printed somewhere fleetwide recently to determine whether the
message in question is still present or not, since we don't anticipate
that it should be printed anywhere, but still need to monitor for its
future presence in the long-term.

This class of issue has happened on a number of occasions, causing
unhealthy machines with hardware issues to remain in production for
longer than ideal. As a recent example, some monitoring around
blk_update_request fell out of date and caused semi-broken machines to
remain in production for longer than would be desirable.

Searching through the codebase to find the message is also extremely
fragile, because many of the messages are further constructed beyond
their callsite (eg. btrfs_printk and other module-specific wrappers,
each with their own functionality). Even if they aren't, guessing the
format and formulation of the underlying message based on the aesthetics
of the message emitted is not a recipe for success at scale, and our
previous issues with fleetwide machine health checking demonstrate as
much.

This provides a solution to the issue of silently changed or deleted
printks: we record pointers to all printk format strings known at
compile time into a new .printk_index section, both in vmlinux and
modules. At runtime, this can then be iterated by looking at
<debugfs>/printk/index/<module>, which emits the following format, both
readable by humans and able to be parsed by machines:

    $ head -1 vmlinux; shuf -n 5 vmlinux
    # <level[,flags]> filename:line function "format"
    <5> block/blk-settings.c:661 disk_stack_limits "%s: Warning: Device %s is misaligned\n"
    <4> kernel/trace/trace.c:8296 trace_create_file "Could not create tracefs '%s' entry\n"
    <6> arch/x86/kernel/hpet.c:144 _hpet_print_config "hpet: %s(%d):\n"
    <6> init/do_mounts.c:605 prepare_namespace "Waiting for root device %s...\n"
    <6> drivers/acpi/osl.c:1410 acpi_no_auto_serialize_setup "ACPI: auto-serialization disabled\n"

This mitigates the majority of cases where we have a highly-specific
printk which we want to match on, as we can now enumerate and check
whether the format changed or the printk callsite disappeared entirely
in userspace. This allows us to catch changes to printks we monitor
earlier and decide what to do about it before it becomes problematic.

There is no additional runtime cost for printk callers or printk itself,
and the assembly generated is exactly the same.

Signed-off-by: Chris Down <chris@chrisdown.name>
Cc: Petr Mladek <pmladek@suse.com>
Cc: Jessica Yu <jeyu@kernel.org>
Cc: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Cc: John Ogness <john.ogness@linutronix.de>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
Cc: Johannes Weiner <hannes@cmpxchg.org>
Cc: Kees Cook <keescook@chromium.org>
Reviewed-by: Petr Mladek <pmladek@suse.com>
Tested-by: Petr Mladek <pmladek@suse.com>
Reported-by: kernel test robot <lkp@intel.com>
Acked-by: Andy Shevchenko <andy.shevchenko@gmail.com>
Acked-by: Jessica Yu <jeyu@kernel.org> # for module.{c,h}
Signed-off-by: Petr Mladek <pmladek@suse.com>
Link: https://lore.kernel.org/r/e42070983637ac5e384f17fbdbe86d19c7b212a5.1623775748.git.chris@chrisdown.name
2021-07-19 11:57:48 +02:00

222 lines
6.8 KiB
ArmAsm

/* SPDX-License-Identifier: GPL-2.0-only */
/*
* linux/arch/arm/lib/backtrace-clang.S
*
* Copyright (C) 2019 Nathan Huckleberry
*
*/
#include <linux/kern_levels.h>
#include <linux/linkage.h>
#include <asm/assembler.h>
.text
/* fp is 0 or stack frame */
#define frame r4
#define sv_fp r5
#define sv_pc r6
#define mask r7
#define sv_lr r8
#define loglvl r9
ENTRY(c_backtrace)
#if !defined(CONFIG_FRAME_POINTER) || !defined(CONFIG_PRINTK)
ret lr
ENDPROC(c_backtrace)
#else
/*
* Clang does not store pc or sp in function prologues so we don't know exactly
* where the function starts.
*
* We can treat the current frame's lr as the saved pc and the preceding
* frame's lr as the current frame's lr, but we can't trace the most recent
* call. Inserting a false stack frame allows us to reference the function
* called last in the stacktrace.
*
* If the call instruction was a bl we can look at the callers branch
* instruction to calculate the saved pc. We can recover the pc in most cases,
* but in cases such as calling function pointers we cannot. In this case,
* default to using the lr. This will be some address in the function, but will
* not be the function start.
*
* Unfortunately due to the stack frame layout we can't dump r0 - r3, but these
* are less frequently saved.
*
* Stack frame layout:
* <larger addresses>
* saved lr
* frame=> saved fp
* optionally saved caller registers (r4 - r10)
* optionally saved arguments (r0 - r3)
* <top of stack frame>
* <smaller addresses>
*
* Functions start with the following code sequence:
* corrected pc => stmfd sp!, {..., fp, lr}
* add fp, sp, #x
* stmfd sp!, {r0 - r3} (optional)
*
*
*
*
*
*
* The diagram below shows an example stack setup for dump_stack.
*
* The frame for c_backtrace has pointers to the code of dump_stack. This is
* why the frame of c_backtrace is used to for the pc calculation of
* dump_stack. This is why we must move back a frame to print dump_stack.
*
* The stored locals for dump_stack are in dump_stack's frame. This means that
* to fully print dump_stack's frame we need both the frame for dump_stack (for
* locals) and the frame that was called by dump_stack (for pc).
*
* To print locals we must know where the function start is. If we read the
* function prologue opcodes we can determine which variables are stored in the
* stack frame.
*
* To find the function start of dump_stack we can look at the stored LR of
* show_stack. It points at the instruction directly after the bl dump_stack.
* We can then read the offset from the bl opcode to determine where the branch
* takes us. The address calculated must be the start of dump_stack.
*
* c_backtrace frame dump_stack:
* {[LR] } ============| ...
* {[FP] } =======| | bl c_backtrace
* | |=> ...
* {[R4-R10]} |
* {[R0-R3] } | show_stack:
* dump_stack frame | ...
* {[LR] } =============| bl dump_stack
* {[FP] } <=======| |=> ...
* {[R4-R10]}
* {[R0-R3] }
*/
stmfd sp!, {r4 - r9, fp, lr} @ Save an extra register
@ to ensure 8 byte alignment
movs frame, r0 @ if frame pointer is zero
beq no_frame @ we have no stack frames
mov loglvl, r2
tst r1, #0x10 @ 26 or 32-bit mode?
moveq mask, #0xfc000003
movne mask, #0 @ mask for 32-bit
/*
* Switches the current frame to be the frame for dump_stack.
*/
add frame, sp, #24 @ switch to false frame
for_each_frame: tst frame, mask @ Check for address exceptions
bne no_frame
/*
* sv_fp is the stack frame with the locals for the current considered
* function.
*
* sv_pc is the saved lr frame the frame above. This is a pointer to a code
* address within the current considered function, but it is not the function
* start. This value gets updated to be the function start later if it is
* possible.
*/
1001: ldr sv_pc, [frame, #4] @ get saved 'pc'
1002: ldr sv_fp, [frame, #0] @ get saved fp
teq sv_fp, mask @ make sure next frame exists
beq no_frame
/*
* sv_lr is the lr from the function that called the current function. This is
* a pointer to a code address in the current function's caller. sv_lr-4 is
* the instruction used to call the current function.
*
* This sv_lr can be used to calculate the function start if the function was
* called using a bl instruction. If the function start can be recovered sv_pc
* is overwritten with the function start.
*
* If the current function was called using a function pointer we cannot
* recover the function start and instead continue with sv_pc as an arbitrary
* value within the current function. If this is the case we cannot print
* registers for the current function, but the stacktrace is still printed
* properly.
*/
1003: ldr sv_lr, [sv_fp, #4] @ get saved lr from next frame
ldr r0, [sv_lr, #-4] @ get call instruction
ldr r3, .Lopcode+4
and r2, r3, r0 @ is this a bl call
teq r2, r3
bne finished_setup @ give up if it's not
and r0, #0xffffff @ get call offset 24-bit int
lsl r0, r0, #8 @ sign extend offset
asr r0, r0, #8
ldr sv_pc, [sv_fp, #4] @ get lr address
add sv_pc, sv_pc, #-4 @ get call instruction address
add sv_pc, sv_pc, #8 @ take care of prefetch
add sv_pc, sv_pc, r0, lsl #2@ find function start
finished_setup:
bic sv_pc, sv_pc, mask @ mask PC/LR for the mode
/*
* Print the function (sv_pc) and where it was called from (sv_lr).
*/
1004: mov r0, sv_pc
mov r1, sv_lr
mov r2, frame
bic r1, r1, mask @ mask PC/LR for the mode
mov r3, loglvl
bl dump_backtrace_entry
/*
* Test if the function start is a stmfd instruction to determine which
* registers were stored in the function prologue.
*
* If we could not recover the sv_pc because we were called through a function
* pointer the comparison will fail and no registers will print. Unwinding will
* continue as if there had been no registers stored in this frame.
*/
1005: ldr r1, [sv_pc, #0] @ if stmfd sp!, {..., fp, lr}
ldr r3, .Lopcode @ instruction exists,
teq r3, r1, lsr #11
ldr r0, [frame] @ locals are stored in
@ the preceding frame
subeq r0, r0, #4
mov r2, loglvl
bleq dump_backtrace_stm @ dump saved registers
/*
* If we are out of frames or if the next frame is invalid.
*/
teq sv_fp, #0 @ zero saved fp means
beq no_frame @ no further frames
cmp sv_fp, frame @ next frame must be
mov frame, sv_fp @ above the current frame
bhi for_each_frame
1006: adr r0, .Lbad
mov r1, loglvl
mov r2, frame
bl _printk
no_frame: ldmfd sp!, {r4 - r9, fp, pc}
ENDPROC(c_backtrace)
.pushsection __ex_table,"a"
.align 3
.long 1001b, 1006b
.long 1002b, 1006b
.long 1003b, 1006b
.long 1004b, 1006b
.long 1005b, 1006b
.popsection
.Lbad: .asciz "%sBacktrace aborted due to bad frame pointer <%p>\n"
.align
.Lopcode: .word 0xe92d4800 >> 11 @ stmfd sp!, {... fp, lr}
.word 0x0b000000 @ bl if these bits are set
#endif