Re: [PATCH v2 04/12] module: Add printk format to add module build ID to stacktraces
Quoting Petr Mladek (2021-03-30 03:29:24)
> On Tue 2021-03-23 19:04:35, Stephen Boyd wrote:
> > Let's make kernel stacktraces easier to identify by including the build
> > ID[1] of a module if the stacktrace is printing a symbol from a module.
> >
> > Example:
> >
> > WARNING: CPU: 3 PID: 3373 at drivers/misc/lkdtm/bugs.c:83
> > lkdtm_WARNING+0x28/0x30 [lkdtm]
> > Modules linked in: lkdtm rfcomm algif_hash algif_skcipher af_alg xt_cgroup
> > uinput xt_MASQUERADE hci_uart
> > CPU: 3 PID: 3373 Comm: bash Not tainted 5.11 #12
> > a8c0d47f7051f3e6670ceaea724af66a39c6cec8
>
> I tested it with "echo l >/proc/sysrq-trigger" and I got the following
> output:
>
> [ 71.905593] CPU: 0 PID: 1762 Comm: bash Kdump: loaded Not tainted
> 5.12.0-rc5-default+ #167 0080
>
>
> It does not looks like an unique build-id.
> Any idea what was going wrong?
Hmm not sure. What does 'hexdump /sys/kernel/notes' show or 'file
vmlinux' parse out of the kernel image?
>
> > --- a/include/linux/kallsyms.h
> > +++ b/include/linux/kallsyms.h
> > @@ -91,6 +93,7 @@ const char *kallsyms_lookup(unsigned long addr,
> >
> > /* Look up a kernel symbol and return it in a text buffer. */
> > extern int sprint_symbol(char *buffer, unsigned long address);
> > +extern int sprint_symbol_stacktrace(char *buffer, unsigned long address);
> > extern int sprint_symbol_no_offset(char *buffer, unsigned long address);
> > extern int sprint_backtrace(char *buffer, unsigned long address);
>
> Could we use a more clear name? It is hard to guess what is
> the difference between sprint_*_stacktrace() and sprint_backtrace().
>
> What about sprint_symbol_build_id() ?
Sure.
>
>
> > diff --git a/kernel/module.c b/kernel/module.c
> > index 30479355ab85..9e9cb502fb33 100644
> > --- a/kernel/module.c
> > +++ b/kernel/module.c
> > @@ -2770,6 +2771,20 @@ static void add_kallsyms(struct module *mod, const
> > struct load_info *info)
> > }
> > mod->core_kallsyms.num_symtab = ndst;
> > }
> > +
> > +static void init_build_id(struct module *mod, const struct load_info *info)
> > +{
> > + const Elf_Shdr *sechdr;
> > + unsigned int i;
> > +
> > + for (i = 0; i < info->hdr->e_shnum; i++) {
> > + sechdr = &info->sechdrs[i];
> > + if (!sect_empty(sechdr) && sechdr->sh_type == SHT_NOTE &&
> > + !build_id_parse_buf((void *)sechdr->sh_addr,
> > mod->build_id,
> > + sechdr->sh_size))
> > + break;
> > + }
>
> Just to be sure. Is this really reliable way how to find the build ID,
> please?
>
The build ID is always part of a note section, so if we parse the notes
and find a build ID type of section (see nhdr->n_type == BUILD_ID) with
a GNU name then we know we have the right section and will be able to
parse the ID out of the buffer.
Re: [PATCH v2 04/12] module: Add printk format to add module build ID to stacktraces
On Wed 2021-03-24 15:28:43, Stephen Boyd wrote: > Quoting Rasmus Villemoes (2021-03-24 15:21:34) > > On 24/03/2021 20.11, Stephen Boyd wrote: > > > Quoting Rasmus Villemoes (2021-03-24 02:57:13) > > > > >> > > >> Is there any reason you didn't just make b an optional flag that could > > >> be specified with or without R? I suppose the parsing is more difficult > > >> with several orthogonal flags (see escaped_string()), but it's a little > > >> easier to understand. Dunno, it's not like we're gonna think of 10 other > > >> things that could be printed for a symbol, so perhaps it's fine. > > >> > > > > > > I think I follow. So %pSb or %pSRb? If it's easier to understand then > > > sure. I was trying to avoid checking another character beyond fmt[1] but > > > it should be fine if fmt[1] is already 'R'. > > I'm inclined to use %pSb and %pSRb. The code looks to simpler and I > suppose we can worry about different ordering/combination problems if it > comes to it. > > ---8<--- > diff --git a/lib/vsprintf.c b/lib/vsprintf.c > index 41ddc353ebb8..0e94cba5ba20 100644 > --- a/lib/vsprintf.c > +++ b/lib/vsprintf.c > @@ -968,6 +968,8 @@ char *symbol_string(char *buf, char *end, void *ptr, > #ifdef CONFIG_KALLSYMS > if (*fmt == 'B') > sprint_backtrace(sym, value); > + else if (*fmt == 'S' && (fmt[1] == 'b' || (fmt[1] == 'R' && fmt[2] == > 'b'))) > + sprint_symbol_stacktrace(sym, value); > else if (*fmt != 's') > sprint_symbol(sym, value); > else I prefer the extra "b" flag as well. It helps me to understand and memorize[*] the meaning. [*] at least short-time memorize ;-) Best Regards, Petr
Re: [PATCH v2 04/12] module: Add printk format to add module build ID to stacktraces
On Tue 2021-03-23 19:04:35, Stephen Boyd wrote:
> Let's make kernel stacktraces easier to identify by including the build
> ID[1] of a module if the stacktrace is printing a symbol from a module.
>
> Example:
>
> WARNING: CPU: 3 PID: 3373 at drivers/misc/lkdtm/bugs.c:83
> lkdtm_WARNING+0x28/0x30 [lkdtm]
> Modules linked in: lkdtm rfcomm algif_hash algif_skcipher af_alg xt_cgroup
> uinput xt_MASQUERADE hci_uart
> CPU: 3 PID: 3373 Comm: bash Not tainted 5.11 #12
> a8c0d47f7051f3e6670ceaea724af66a39c6cec8
I tested it with "echo l >/proc/sysrq-trigger" and I got the following
output:
[ 71.905593] CPU: 0 PID: 1762 Comm: bash Kdump: loaded Not tainted
5.12.0-rc5-default+ #167 0080
It does not looks like an unique build-id.
Any idea what was going wrong?
> --- a/include/linux/kallsyms.h
> +++ b/include/linux/kallsyms.h
> @@ -91,6 +93,7 @@ const char *kallsyms_lookup(unsigned long addr,
>
> /* Look up a kernel symbol and return it in a text buffer. */
> extern int sprint_symbol(char *buffer, unsigned long address);
> +extern int sprint_symbol_stacktrace(char *buffer, unsigned long address);
> extern int sprint_symbol_no_offset(char *buffer, unsigned long address);
> extern int sprint_backtrace(char *buffer, unsigned long address);
Could we use a more clear name? It is hard to guess what is
the difference between sprint_*_stacktrace() and sprint_backtrace().
What about sprint_symbol_build_id() ?
> diff --git a/kernel/module.c b/kernel/module.c
> index 30479355ab85..9e9cb502fb33 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -2770,6 +2771,20 @@ static void add_kallsyms(struct module *mod, const
> struct load_info *info)
> }
> mod->core_kallsyms.num_symtab = ndst;
> }
> +
> +static void init_build_id(struct module *mod, const struct load_info *info)
> +{
> + const Elf_Shdr *sechdr;
> + unsigned int i;
> +
> + for (i = 0; i < info->hdr->e_shnum; i++) {
> + sechdr = &info->sechdrs[i];
> + if (!sect_empty(sechdr) && sechdr->sh_type == SHT_NOTE &&
> + !build_id_parse_buf((void *)sechdr->sh_addr, mod->build_id,
> + sechdr->sh_size))
> + break;
> + }
Just to be sure. Is this really reliable way how to find the build ID,
please?
> +}
> #else
> static inline void layout_symtab(struct module *mod, struct load_info *info)
> {
> @@ -2778,6 +2793,10 @@ static inline void layout_symtab(struct module *mod,
> struct load_info *info)
> static void add_kallsyms(struct module *mod, const struct load_info *info)
> {
> }
Best Regards,
Petr
Re: [PATCH v2 04/12] module: Add printk format to add module build ID to stacktraces
Quoting Rasmus Villemoes (2021-03-24 15:21:34) > On 24/03/2021 20.11, Stephen Boyd wrote: > > Quoting Rasmus Villemoes (2021-03-24 02:57:13) > > >> > >> Is there any reason you didn't just make b an optional flag that could > >> be specified with or without R? I suppose the parsing is more difficult > >> with several orthogonal flags (see escaped_string()), but it's a little > >> easier to understand. Dunno, it's not like we're gonna think of 10 other > >> things that could be printed for a symbol, so perhaps it's fine. > >> > > > > I think I follow. So %pSb or %pSRb? If it's easier to understand then > > sure. I was trying to avoid checking another character beyond fmt[1] but > > it should be fine if fmt[1] is already 'R'. > > > > I don't know. On the one hand, it seems sensible to allow such "flag" > modifiers to appear independently and in any order. Because what if some > day we think of some other property of the symbol we might want to > provide access to via a "z" flag; when to allow all combinations of the > R, b and z functionality we'd have to use four more random letters to > stand for various combinations of those flags. On the other hand, > vsprintf.c is already a complete wild west of odd conventions for > %p, and it's not like symbol_string() gets extended every other > release, and I can certainly understand the desire to keep the parsing > of fmt minimal. So 'r' to mean 'Rb' is ok by me if you prefer that. I'm inclined to use %pSb and %pSRb. The code looks to simpler and I suppose we can worry about different ordering/combination problems if it comes to it. ---8<--- diff --git a/lib/vsprintf.c b/lib/vsprintf.c index 41ddc353ebb8..0e94cba5ba20 100644 --- a/lib/vsprintf.c +++ b/lib/vsprintf.c @@ -968,6 +968,8 @@ char *symbol_string(char *buf, char *end, void *ptr, #ifdef CONFIG_KALLSYMS if (*fmt == 'B') sprint_backtrace(sym, value); + else if (*fmt == 'S' && (fmt[1] == 'b' || (fmt[1] == 'R' && fmt[2] == 'b'))) + sprint_symbol_stacktrace(sym, value); else if (*fmt != 's') sprint_symbol(sym, value); else
Re: [PATCH v2 04/12] module: Add printk format to add module build ID to stacktraces
On 24/03/2021 20.11, Stephen Boyd wrote: > Quoting Rasmus Villemoes (2021-03-24 02:57:13) >> >> Is there any reason you didn't just make b an optional flag that could >> be specified with or without R? I suppose the parsing is more difficult >> with several orthogonal flags (see escaped_string()), but it's a little >> easier to understand. Dunno, it's not like we're gonna think of 10 other >> things that could be printed for a symbol, so perhaps it's fine. >> > > I think I follow. So %pSb or %pSRb? If it's easier to understand then > sure. I was trying to avoid checking another character beyond fmt[1] but > it should be fine if fmt[1] is already 'R'. > I don't know. On the one hand, it seems sensible to allow such "flag" modifiers to appear independently and in any order. Because what if some day we think of some other property of the symbol we might want to provide access to via a "z" flag; when to allow all combinations of the R, b and z functionality we'd have to use four more random letters to stand for various combinations of those flags. On the other hand, vsprintf.c is already a complete wild west of odd conventions for %p, and it's not like symbol_string() gets extended every other release, and I can certainly understand the desire to keep the parsing of fmt minimal. So 'r' to mean 'Rb' is ok by me if you prefer that. Rasmus
Re: [PATCH v2 04/12] module: Add printk format to add module build ID to stacktraces
Quoting Rasmus Villemoes (2021-03-24 02:57:13)
> On 24/03/2021 03.04, Stephen Boyd wrote:
>
> > @@ -2778,6 +2793,10 @@ static inline void layout_symtab(struct module *mod,
> > struct load_info *info)
> > static void add_kallsyms(struct module *mod, const struct load_info *info)
> > {
> > }
> > +
> > +static void init_build_id(struct module *mod, const struct load_info *info)
> > +{
> > +}
> > #endif /* CONFIG_KALLSYMS */
> >
> > static void dynamic_debug_setup(struct module *mod, struct _ddebug *debug,
> > unsigned int num)
> > @@ -4004,6 +4023,7 @@ static int load_module(struct load_info *info, const
> > char __user *uargs,
> > goto free_arch_cleanup;
> > }
> >
> > + init_build_id(mod, info);
> > dynamic_debug_setup(mod, info->debug, info->num_debug);
> >
> > /* Ftrace init must be called in the MODULE_STATE_UNFORMED state */
> > @@ -4235,7 +4255,7 @@ void * __weak
> > dereference_module_function_descriptor(struct module *mod,
> > const char *module_address_lookup(unsigned long addr,
> > unsigned long *size,
> > unsigned long *offset,
> > - char **modname,
> > + char **modname, unsigned char **modbuildid,
>
> It's an existing defect with modname, but surely this should take a
> "const unsigned char **modbuildid", no?
Sure.
>
> > char *namebuf)
> > {
> > const char *ret = NULL;
> > @@ -4246,6 +4266,8 @@ const char *module_address_lookup(unsigned long addr,
> > if (mod) {
> > if (modname)
> > *modname = mod->name;
> > + if (modbuildid)
> > + *modbuildid = mod->build_id;
> >
> > ret = find_kallsyms_symbol(mod, addr, size, offset);
> > }
> > diff --git a/lib/vsprintf.c b/lib/vsprintf.c
> > index 41ddc353ebb8..9cd62e84e4aa 100644
> > --- a/lib/vsprintf.c
> > +++ b/lib/vsprintf.c
> > @@ -961,13 +961,15 @@ char *symbol_string(char *buf, char *end, void *ptr,
> > char sym[KSYM_SYMBOL_LEN];
> > #endif
> >
> > - if (fmt[1] == 'R')
> > + if (fmt[1] == 'R' || fmt[1] == 'r')
> > ptr = __builtin_extract_return_addr(ptr);
> > value = (unsigned long)ptr;
> >
> > #ifdef CONFIG_KALLSYMS
> > if (*fmt == 'B')
> > sprint_backtrace(sym, value);
> > + else if (*fmt == 'S' && (fmt[1] == 'b' || fmt[1] == 'r'))
> > + sprint_symbol_stacktrace(sym, value);
> > else if (*fmt != 's')
> > sprint_symbol(sym, value);
> > else
> > @@ -2129,6 +2131,8 @@ early_param("no_hash_pointers",
> > no_hash_pointers_enable);
> > * - 'S' For symbolic direct pointers (or function descriptors) with offset
> > * - 's' For symbolic direct pointers (or function descriptors) without
> > offset
> > * - '[Ss]R' as above with __builtin_extract_return_addr() translation
> > + * - '[Ss]r' as above with __builtin_extract_return_addr() translation and
> > module build ID
> > + * - '[Ss]b' as above with module build ID (for use in backtraces)
>
> The code doesn't quite match the comment. The lowercase s is not handled
> (i.e., there's no way to say "without offset, with build ID"). You don't
> have to fix the code to support that right now, the whole kallsyms
> vsprintf code needs to be reworked inside-out anyway (having vsnprint
> call sprint_symbol* which builds the output using snprintf() calls makes
> me cringe), so please just replace [Ss] by S to make the comment match
> the code - I notice that you did only document the S variant in
> printk-formats.rst.
No problem. Will fix this comment.
>
> Is there any reason you didn't just make b an optional flag that could
> be specified with or without R? I suppose the parsing is more difficult
> with several orthogonal flags (see escaped_string()), but it's a little
> easier to understand. Dunno, it's not like we're gonna think of 10 other
> things that could be printed for a symbol, so perhaps it's fine.
>
I think I follow. So %pSb or %pSRb? If it's easier to understand then
sure. I was trying to avoid checking another character beyond fmt[1] but
it should be fine if fmt[1] is already 'R'.
Re: [PATCH v2 04/12] module: Add printk format to add module build ID to stacktraces
On 24/03/2021 03.04, Stephen Boyd wrote:
> @@ -2778,6 +2793,10 @@ static inline void layout_symtab(struct module *mod,
> struct load_info *info)
> static void add_kallsyms(struct module *mod, const struct load_info *info)
> {
> }
> +
> +static void init_build_id(struct module *mod, const struct load_info *info)
> +{
> +}
> #endif /* CONFIG_KALLSYMS */
>
> static void dynamic_debug_setup(struct module *mod, struct _ddebug *debug,
> unsigned int num)
> @@ -4004,6 +4023,7 @@ static int load_module(struct load_info *info, const
> char __user *uargs,
> goto free_arch_cleanup;
> }
>
> + init_build_id(mod, info);
> dynamic_debug_setup(mod, info->debug, info->num_debug);
>
> /* Ftrace init must be called in the MODULE_STATE_UNFORMED state */
> @@ -4235,7 +4255,7 @@ void * __weak
> dereference_module_function_descriptor(struct module *mod,
> const char *module_address_lookup(unsigned long addr,
> unsigned long *size,
> unsigned long *offset,
> - char **modname,
> + char **modname, unsigned char **modbuildid,
It's an existing defect with modname, but surely this should take a
"const unsigned char **modbuildid", no?
> char *namebuf)
> {
> const char *ret = NULL;
> @@ -4246,6 +4266,8 @@ const char *module_address_lookup(unsigned long addr,
> if (mod) {
> if (modname)
> *modname = mod->name;
> + if (modbuildid)
> + *modbuildid = mod->build_id;
>
> ret = find_kallsyms_symbol(mod, addr, size, offset);
> }
> diff --git a/lib/vsprintf.c b/lib/vsprintf.c
> index 41ddc353ebb8..9cd62e84e4aa 100644
> --- a/lib/vsprintf.c
> +++ b/lib/vsprintf.c
> @@ -961,13 +961,15 @@ char *symbol_string(char *buf, char *end, void *ptr,
> char sym[KSYM_SYMBOL_LEN];
> #endif
>
> - if (fmt[1] == 'R')
> + if (fmt[1] == 'R' || fmt[1] == 'r')
> ptr = __builtin_extract_return_addr(ptr);
> value = (unsigned long)ptr;
>
> #ifdef CONFIG_KALLSYMS
> if (*fmt == 'B')
> sprint_backtrace(sym, value);
> + else if (*fmt == 'S' && (fmt[1] == 'b' || fmt[1] == 'r'))
> + sprint_symbol_stacktrace(sym, value);
> else if (*fmt != 's')
> sprint_symbol(sym, value);
> else
> @@ -2129,6 +2131,8 @@ early_param("no_hash_pointers",
> no_hash_pointers_enable);
> * - 'S' For symbolic direct pointers (or function descriptors) with offset
> * - 's' For symbolic direct pointers (or function descriptors) without
> offset
> * - '[Ss]R' as above with __builtin_extract_return_addr() translation
> + * - '[Ss]r' as above with __builtin_extract_return_addr() translation and
> module build ID
> + * - '[Ss]b' as above with module build ID (for use in backtraces)
The code doesn't quite match the comment. The lowercase s is not handled
(i.e., there's no way to say "without offset, with build ID"). You don't
have to fix the code to support that right now, the whole kallsyms
vsprintf code needs to be reworked inside-out anyway (having vsnprint
call sprint_symbol* which builds the output using snprintf() calls makes
me cringe), so please just replace [Ss] by S to make the comment match
the code - I notice that you did only document the S variant in
printk-formats.rst.
Is there any reason you didn't just make b an optional flag that could
be specified with or without R? I suppose the parsing is more difficult
with several orthogonal flags (see escaped_string()), but it's a little
easier to understand. Dunno, it's not like we're gonna think of 10 other
things that could be printed for a symbol, so perhaps it's fine.
Rasmus
[PATCH v2 04/12] module: Add printk format to add module build ID to stacktraces
Let's make kernel stacktraces easier to identify by including the build ID[1] of a module if the stacktrace is printing a symbol from a module. This makes it simpler for developers to locate a kernel module's full debuginfo for a particular stacktrace. Combined with scripts/decode_stracktrace.sh, a developer can download the matching debuginfo from a debuginfod[2] server and find the exact file and line number for the functions plus offsets in a stacktrace that match the module. This is especially useful for pstore crash debugging where the kernel crashes are recorded in something like console-ramoops and the recovery kernel/modules are different or the debuginfo doesn't exist on the device due to space concerns (the debuginfo can be too large for space limited devices). Originally, I put this on the %pS format, but that was quickly rejected given that %pS is used in other places such as ftrace where build IDs aren't meaningful. There was some discussions on the list to put every module build ID into the "Modules linked in:" section of the stacktrace message but that quickly becomes very hard to read once you have more than three or four modules linked in. It also provides too much information when we don't expect each module to be traversed in a stacktrace. Having the build ID for modules that aren't important just makes things messy. Splitting it to multiple lines for each module quickly explodes the number of lines printed in an oops too, possibly wrapping the warning off the console. And finally, trying to stash away each module used in a callstack to provide the ID of each symbol printed is cumbersome and would require changes to each architecture to stash away modules and return their build IDs once unwinding has completed. Instead, we opt for the simpler approach of introducing a new printk format '%p[sS][br]' for "pointer symbolic backtrace with module build ID" and then updating the few places in the architecture layer where the stacktrace is printed to use this new format. Example: WARNING: CPU: 3 PID: 3373 at drivers/misc/lkdtm/bugs.c:83 lkdtm_WARNING+0x28/0x30 [lkdtm] Modules linked in: lkdtm rfcomm algif_hash algif_skcipher af_alg xt_cgroup uinput xt_MASQUERADE hci_uart CPU: 3 PID: 3373 Comm: bash Not tainted 5.11 #12 a8c0d47f7051f3e6670ceaea724af66a39c6cec8 Hardware name: Google Lazor (rev3+) with KB Backlight (DT) pstate: 0049 (nzcv daif +PAN -UAO -TCO BTYPE=--) pc : lkdtm_WARNING+0x28/0x30 [lkdtm] lr : lkdtm_do_action+0x24/0x40 [lkdtm] sp : ffc013febca0 x29: ffc013febca0 x28: ff88d9438040 x27: x26: x25: x24: ffdd0e9772c0 x23: 0020 x22: ffdd0e975366 x21: ffdd0e9772e0 x20: ffc013febde0 x19: 0008 x18: x17: x16: 0037 x15: ffdd102ab174 x14: 0003 x13: 0004 x12: x11: x10: x9 : 0001 x8 : ffdd0e979000 x7 : x6 : ffdd10ff6b54 x5 : x4 : x3 : ffc013feb938 x2 : ff89fef05a70 x1 : ff89feef5788 x0 : ffdd0e9772e0 Call trace: lkdtm_WARNING+0x28/0x30 [lkdtm 6c2215028606bda50de823490723dc4bc5bf46f9] direct_entry+0x16c/0x1b4 [lkdtm 6c2215028606bda50de823490723dc4bc5bf46f9] full_proxy_write+0x74/0xa4 vfs_write+0xec/0x2e8 ksys_write+0x84/0xf0 __arm64_sys_write+0x24/0x30 el0_svc_common+0xf4/0x1c0 do_el0_svc_compat+0x28/0x3c el0_svc_compat+0x10/0x1c el0_sync_compat_handler+0xa8/0xcc el0_sync_compat+0x178/0x180 ---[ end trace f89bc7f5417cbcc6 ]--- Cc: Jiri Olsa Cc: Alexei Starovoitov Cc: Jessica Yu Cc: Evan Green Cc: Hsin-Yi Wang Cc: Petr Mladek Cc: Steven Rostedt Cc: Sergey Senozhatsky Cc: Andy Shevchenko Cc: Rasmus Villemoes Cc: Cc: Matthew Wilcox Link: https://fedoraproject.org/wiki/Releases/FeatureBuildId [1] Link: https://sourceware.org/elfutils/Debuginfod.html [2] Signed-off-by: Stephen Boyd --- Documentation/core-api/printk-formats.rst | 9 +++ include/linux/kallsyms.h | 13 +++- include/linux/module.h| 6 +- kernel/kallsyms.c | 73 --- kernel/module.c | 24 +++- lib/vsprintf.c| 6 +- 6 files changed, 106 insertions(+), 25 deletions(-) diff --git a/Documentation/core-api/printk-formats.rst b/Documentation/core-api/printk-formats.rst index 160e710d992f..c0844cb275eb 100644 --- a/Documentation/core-api/printk-formats.rst +++ b/Documentation/core-api/printk-formats.rst @@ -114,6 +114,15 @@ used when printing stack backtraces. The specifier takes into consideration the effect of compiler optimisations which may occur when tail-calls are used and marked with the noreturn GCC attribute. +If the pointer is within a module, the module name and optionally build ID is +printed after the symbo
