All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
       [not found] ` <LO2P265MB267173F563B0A2CA5995FA2C939F9@LO2P265MB2671.GBRP265.PROD.OUTLOOK.COM>
@ 2021-11-22 14:02   ` Vimal Agrawal
  2021-12-08 19:33     ` Luis Chamberlain
  0 siblings, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2021-11-22 14:02 UTC (permalink / raw)
  To: mcgrof, jeyu, linux-kernel

If kernel modules are stripped off symbols (say built by using strip --
strip-unneeded) then stack traces in dmesg do not show module name or
symbol name for addresses. It just prints absolute address ( without any
reference of module)
e.g.

[245864.699580]  do_nmi+0x12f/0x370
[245864.699583]  end_repeat_nmi+0x16/0x50
[245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
[245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
[245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
[245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
[245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
[245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
[245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
[245864.699590]  ? 0xffffffffc06b61a0
[245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
[245864.699593]  ? 0xffffffffc06b67ec
[245864.699594]  </NMI>

Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
stack trace as absolute address.
There is no easy way in case box crashes as we loose /proc/modules to see
load address of modules to map address to one specific module. It will be
really good to give some hint of module and offset inside module section
about such addresses.

so changed kernel/module.c so that it can decode address to _MODULE_START_+
offset/size or _MODULE_INIT_+offset/size depending on where the address
lies (in core/.text or init/.init.text section of module).

e.g. nfnm_queue_net_init+0x2f1/0x393 [nfnetmap_queue] printed in case of
symbols present shows up as 0010:0xffffffffc06b67ec in case symbols are
absent. With modified logic, it will be shown as _MODULE_INIT_+0x2f1/0x393
[nfnetmap_queue]

This will help for developer to debug and map this to actual nfnm_queue_net
_init symbol later. One can use objdump/readelf/nm to find symbols with
offset in .init.text and .text sections.

tests done:
===========
1. added WARN_ON_ONE(1) in init_module of a module
----------------------------------------------------
[53.795977] task: ffff9d60094b3000 task.stack: ffff9d602c704000
[53.795978] RIP: 0010:_MODULE_INIT_+0x2f1/0x393 [nfnetmap_queue]   <=====
[53.795979] RSP: 0018:ffff9d602c707c40 EFLAGS: 00010286
[53.795980] RAX: 0000000000000047 RBX: ffff9d600b4c0800 RCX: 0000000000000006
[53.795980] RDX: 0000000000000007 RSI: 0000000000000096 RDI: ffff9d603fc172f0
[53.795981] RBP: 0000000000000000 R08: 00000000000004bd R09: 0000000000000002
[53.795981] R10: ffffffffc2250083 R11: 0000000000000001 R12: ffff9d5fb785a870
[53.795982] R13: 00000000fffffff4 R14: ffff9d5fb785a800 R15: 0000000000000000
[53.795983] FS:  00007ffb73c2ab80(0000) GS:ffff9d603fc00000(0000)
[53.795983] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[53.795984] CR2: 00000000f76e6270 CR3: 0000000107c0c006 CR4: 00000000001606f0
[53.796014] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[53.796014] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[53.796015] Call Trace:
[53.796022]  ops_init.constprop.8+0x81/0x110
[53.796024]  register_pernet_operations+0x92/0xc0
[53.796026]  ? _MODULE_INIT_+0x393/0x393 [nfnetmap_queue]          <======
[53.796027]  register_pernet_subsys+0x1f/0x40
[53.796028]  init_module+0x51/0xc6d [nfnetmap_queue]
[53.796031]  do_one_initcall+0x36/0x160

2. added a call to sprint_symbol in a module
---------------------------------------------
$ decode for symbol nfnm_queue_flush+16:
_MODULE_START_+0x7e0/0x1daa [nfnetmap_queue]                       <======

$ nm nfnetmap_queue.ko | grep _flush
00000000000007d0 t nfnm_queue_flush
0x7d0 + 16d = 0x7e0 so this offset maps to symbol nfnm_queue_flush

tested on kernel 4.14.38

Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
---
 kernel/module.c | 21 +++++++++++++++++----
 1 file changed, 17 insertions(+), 4 deletions(-)

diff --git a/kernel/module.c b/kernel/module.c
index 84a9141a5e15..d55fb8405151 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -4259,12 +4259,19 @@ static const char *find_kallsyms_symbol(struct module *mod,
        unsigned int i, best = 0;
        unsigned long nextval, bestval;
        struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
+       char *module_base_name = "_MODULE_START_";
+       unsigned long module_base_address = 0;

        /* At worse, next value is at end of module */
-       if (within_module_init(addr, mod))
+       if (within_module_init(addr, mod)) {
                nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
-       else
+               module_base_address = (unsigned long)mod->init_layout.base;
+               module_base_name = "_MODULE_INIT_";
+       } else {
                nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
+               module_base_address = (unsigned long)mod->core_layout.base;
+               module_base_name = "_MODULE_START_";
+       }

        bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);

@@ -4295,8 +4302,14 @@ static const char *find_kallsyms_symbol(struct module *mod,
                        nextval = thisval;
        }

-       if (!best)
-               return NULL;
+       if (!best) {
+               /* return MODULE base and offset from it */
+               if (size)
+                       *size = nextval - module_base_address;
+               if (offset)
+                       *offset = addr - module_base_address;
+               return module_base_name;
+       }

        if (size)
                *size = nextval - bestval;
-- 
2.17.1






^ permalink raw reply related	[flat|nested] 36+ messages in thread

* Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
  2021-11-22 14:02   ` [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules Vimal Agrawal
@ 2021-12-08 19:33     ` Luis Chamberlain
  2021-12-09  5:37       ` Vimal Agrawal
  0 siblings, 1 reply; 36+ messages in thread
From: Luis Chamberlain @ 2021-12-08 19:33 UTC (permalink / raw)
  To: Vimal Agrawal, Masahiro Yamada, Michal Marek, Nick Desaulniers,
	Jan Beulich, Jeff Mahoney, Sam Ravnborg, linux-kbuild
  Cc: jeyu, linux-kernel

Thanks for your patch! I will note to start off with that unfortunately
whatever it is you use to send emails leaves them with UTF encodings
which does not let me easily download the patches using lore. For
instance, this is what I see:

https://lore.kernel.org/all/106F23FD-3768-4CF0-893D-EDFE4A0BA2BF@sophos.com/raw

Here is an example of a good patch:

https://lore.kernel.org/all/20211129034509.2646872-2-ming.lei@redhat.com/raw

What are you using to send patches? Consider using git send-email.
I think your mailer is sending the emails out as MIME attachments.

On Mon, Nov 22, 2021 at 02:02:30PM +0000, Vimal Agrawal wrote:
> If kernel modules are stripped off symbols (say built by using strip --
> strip-unneeded)

OK so is your build system using something like:

make install modules_install INSTALL_MOD_STRIP="--strip-unneeded"

At least that's one way to strip modules using upstream techniques since
the 2.6 kernel days. Because it would be wise for us to document *how* to
reproduce the issue you are seeing in your commit log.

> then stack traces in dmesg do not show module name or
> symbol name for addresses.

as intended. So there is actually no issue and your patch is not a fix.
It is an optimization to help readers with a hint. So if we get anywhere
with this patch I'd say change the subject to relate it to
a heuristic enhancement for INSTALL_MOD_STRIP when --strip-unneeded is used.

> It just prints absolute address ( without any
> reference of module)
> e.g.
> 
> [245864.699580]  do_nmi+0x12f/0x370
> [245864.699583]  end_repeat_nmi+0x16/0x50
> [245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
> [245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
> [245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
> [245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
> [245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
> [245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
> [245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
> [245864.699590]  ? 0xffffffffc06b61a0
> [245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
> [245864.699593]  ? 0xffffffffc06b67ec
> [245864.699594]  </NMI>
> 
> Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
> stack trace as absolute address.
> There is no easy way in case box crashes as we loose /proc/modules to see
> load address of modules to map address to one specific module. It will be
> really good to give some hint of module and offset inside module section
> about such addresses.
> 
> so changed kernel/module.c so that it can decode address to _MODULE_START_+
> offset/size or _MODULE_INIT_+offset/size depending on where the address
> lies (in core/.text or init/.init.text section of module).
> 
> e.g. nfnm_queue_net_init+0x2f1/0x393 [nfnetmap_queue] printed in case of
> symbols present shows up as 0010:0xffffffffc06b67ec in case symbols are
> absent. With modified logic, it will be shown as _MODULE_INIT_+0x2f1/0x393
> [nfnetmap_queue]
> 
> This will help for developer to debug and map this to actual nfnm_queue_net
> _init symbol later. One can use objdump/readelf/nm to find symbols with
> offset in .init.text and .text sections.
> 
> tests done:
> ===========
> 1. added WARN_ON_ONE(1) in init_module of a module
> ----------------------------------------------------
> [53.795977] task: ffff9d60094b3000 task.stack: ffff9d602c704000
> [53.795978] RIP: 0010:_MODULE_INIT_+0x2f1/0x393 [nfnetmap_queue]   <=====

Huh, if the module is already printed (the [nfnetmap_queue]) why even
have _MODULE_INIT_ and instead we just say:

[53.795978] RIP: 0010:[module __init]+0x2f1/0x393 [nfnetmap_queue]

This way if you come up with other heuristics this can also be put in
the [] and we'd document that.

> [53.795979] RSP: 0018:ffff9d602c707c40 EFLAGS: 00010286
> [53.795980] RAX: 0000000000000047 RBX: ffff9d600b4c0800 RCX: 0000000000000006
> [53.795980] RDX: 0000000000000007 RSI: 0000000000000096 RDI: ffff9d603fc172f0
> [53.795981] RBP: 0000000000000000 R08: 00000000000004bd R09: 0000000000000002
> [53.795981] R10: ffffffffc2250083 R11: 0000000000000001 R12: ffff9d5fb785a870
> [53.795982] R13: 00000000fffffff4 R14: ffff9d5fb785a800 R15: 0000000000000000
> [53.795983] FS:  00007ffb73c2ab80(0000) GS:ffff9d603fc00000(0000)
> [53.795983] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [53.795984] CR2: 00000000f76e6270 CR3: 0000000107c0c006 CR4: 00000000001606f0
> [53.796014] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [53.796014] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [53.796015] Call Trace:
> [53.796022]  ops_init.constprop.8+0x81/0x110
> [53.796024]  register_pernet_operations+0x92/0xc0
> [53.796026]  ? _MODULE_INIT_+0x393/0x393 [nfnetmap_queue]          <======
> [53.796027]  register_pernet_subsys+0x1f/0x40
> [53.796028]  init_module+0x51/0xc6d [nfnetmap_queue]
> [53.796031]  do_one_initcall+0x36/0x160
> 
> 2. added a call to sprint_symbol in a module
> ---------------------------------------------
> $ decode for symbol nfnm_queue_flush+16:
> _MODULE_START_+0x7e0/0x1daa [nfnetmap_queue]                       <======
> 
> $ nm nfnetmap_queue.ko | grep _flush
> 00000000000007d0 t nfnm_queue_flush
> 0x7d0 + 16d = 0x7e0 so this offset maps to symbol nfnm_queue_flush
> 
> tested on kernel 4.14.38
> 
> Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
> ---
>  kernel/module.c | 21 +++++++++++++++++----
>  1 file changed, 17 insertions(+), 4 deletions(-)
> 
> diff --git a/kernel/module.c b/kernel/module.c
> index 84a9141a5e15..d55fb8405151 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -4259,12 +4259,19 @@ static const char *find_kallsyms_symbol(struct module *mod,
>         unsigned int i, best = 0;
>         unsigned long nextval, bestval;
>         struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
> +       char *module_base_name = "_MODULE_START_";

I don't think "_MODULE_START_" tells the user anything clear.
If we're going to use heuristics best we use a nomenclature we
can expand later and not be cryptic.

So maybe just [module] is good enough.

We don't have to initialize this as well, as its either one or the other.

> +       unsigned long module_base_address = 0;
> 
>         /* At worse, next value is at end of module */
> -       if (within_module_init(addr, mod))
> +       if (within_module_init(addr, mod)) {
>                 nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
> -       else
> +               module_base_address = (unsigned long)mod->init_layout.base;
> +               module_base_name = "_MODULE_INIT_";
> +       } else {
>                 nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
> +               module_base_address = (unsigned long)mod->core_layout.base;
> +               module_base_name = "_MODULE_START_";
> +       }
> 
>         bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
> 
> @@ -4295,8 +4302,14 @@ static const char *find_kallsyms_symbol(struct module *mod,
>                         nextval = thisval;
>         }
> 
> -       if (!best)
> -               return NULL;
> +       if (!best) {
> +               /* return MODULE base and offset from it */
> +               if (size)
> +                       *size = nextval - module_base_address;
> +               if (offset)
> +                       *offset = addr - module_base_address;
> +               return module_base_name;

Have you tested this on recent kernels? If not please test this there
as I cannot reproduce with your changes taking effect at all. In fact
this branch is not hit at all.

  Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
  2021-12-08 19:33     ` Luis Chamberlain
@ 2021-12-09  5:37       ` Vimal Agrawal
  2021-12-09 20:40         ` Luis Chamberlain
  0 siblings, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2021-12-09  5:37 UTC (permalink / raw)
  To: Luis Chamberlain, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild
  Cc: jeyu, linux-kernel

Hi Luis,

My replies in-line under Vimal>>

Thanks,
Vimal

-----Original Message-----
From: Luis Chamberlain <mcgrof@infradead.org> on behalf of Luis Chamberlain <mcgrof@kernel.org>
Date: Thursday, 9 December 2021 at 1:03 AM
To: Vimal Agrawal <Vimal.Agrawal@sophos.com>, Masahiro Yamada <masahiroy@kernel.org>, Michal Marek <michal.lkml@markovi.net>, Nick Desaulniers <ndesaulniers@google.com>, Jan Beulich <JBeulich@suse.com>, Jeff Mahoney <jeffm@suse.com>, Sam Ravnborg <sam@ravnborg.org>, "linux-kbuild@vger.kernel.org" <linux-kbuild@vger.kernel.org>
Cc: "jeyu@kernel.org" <jeyu@kernel.org>, "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>
Subject: Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules

    Thanks for your patch! I will note to start off with that unfortunately
    whatever it is you use to send emails leaves them with UTF encodings
    which does not let me easily download the patches using lore. For
    instance, this is what I see:

    https://lore.kernel.org/all/106F23FD-3768-4CF0-893D-EDFE4A0BA2BF@sophos.com/raw

    Here is an example of a good patch:

    https://lore.kernel.org/all/20211129034509.2646872-2-ming.lei@redhat.com/raw

    What are you using to send patches? Consider using git send-email.
    I think your mailer is sending the emails out as MIME attachments.
Vimal>> I am using outlook app on mac and I changed format to use "plain format text". I will use git send-email from next time for patches.
Thanks for letting me know.

    On Mon, Nov 22, 2021 at 02:02:30PM +0000, Vimal Agrawal wrote:
    > If kernel modules are stripped off symbols (say built by using strip --
    > strip-unneeded)

    OK so is your build system using something like:

    make install modules_install INSTALL_MOD_STRIP="--strip-unneeded"

    At least that's one way to strip modules using upstream techniques since
    the 2.6 kernel days. Because it would be wise for us to document *how* to
    reproduce the issue you are seeing in your commit log.
Vimal>> yes, our build uses INSTALL_MOD_STRIP="--strip-unneeded"

    > then stack traces in dmesg do not show module name or
    > symbol name for addresses.

    as intended. So there is actually no issue and your patch is not a fix.
    It is an optimization to help readers with a hint. So if we get anywhere
    with this patch I'd say change the subject to relate it to
    a heuristic enhancement for INSTALL_MOD_STRIP when --strip-unneeded is used.
Vimal>> yes, problem is only when --strip-unneeded option is used to strip the modules.

    > It just prints absolute address ( without any
    > reference of module)
    > e.g.
    > 
    > [245864.699580]  do_nmi+0x12f/0x370
    > [245864.699583]  end_repeat_nmi+0x16/0x50
    > [245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
    > [245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
    > [245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
    > [245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
    > [245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
    > [245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
    > [245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
    > [245864.699590]  ? 0xffffffffc06b61a0
    > [245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
    > [245864.699593]  ? 0xffffffffc06b67ec
    > [245864.699594]  </NMI>
    > 
    > Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
    > stack trace as absolute address.
    > There is no easy way in case box crashes as we loose /proc/modules to see
    > load address of modules to map address to one specific module. It will be
    > really good to give some hint of module and offset inside module section
    > about such addresses.
    > 
    > so changed kernel/module.c so that it can decode address to _MODULE_START_+
    > offset/size or _MODULE_INIT_+offset/size depending on where the address
    > lies (in core/.text or init/.init.text section of module).
    > 
    > e.g. nfnm_queue_net_init+0x2f1/0x393 [nfnetmap_queue] printed in case of
    > symbols present shows up as 0010:0xffffffffc06b67ec in case symbols are
    > absent. With modified logic, it will be shown as _MODULE_INIT_+0x2f1/0x393
    > [nfnetmap_queue]
    > 
    > This will help for developer to debug and map this to actual nfnm_queue_net
    > _init symbol later. One can use objdump/readelf/nm to find symbols with
    > offset in .init.text and .text sections.
    > 
    > tests done:
    > ===========
    > 1. added WARN_ON_ONE(1) in init_module of a module
    > ----------------------------------------------------
    > [53.795977] task: ffff9d60094b3000 task.stack: ffff9d602c704000
    > [53.795978] RIP: 0010:_MODULE_INIT_+0x2f1/0x393 [nfnetmap_queue]   <=====

    Huh, if the module is already printed (the [nfnetmap_queue]) why even
    have _MODULE_INIT_ and instead we just say:

    [53.795978] RIP: 0010:[module __init]+0x2f1/0x393 [nfnetmap_queue]

    This way if you come up with other heuristics this can also be put in
    the [] and we'd document that.
Vimal>> I am fine with that. I used _MODULE_INIT_ and _MODULE_START_ because I see something similar being reported by bt command in crash utility in these cases.  So I took reference of that. See following bt from crash utility:
<<
#6 [ffff99cdc059b8c0] _MODULE_START_act_mirred at ffffffffc06cd7ee [act_mirred]
 #7 [ffff99cdc059b900] tcf_action_exec at ffffffff864c57bc
 #8 [ffff99cdc059b948] _MODULE_START_cls_u32 at ffffffffc06d2620 [cls_u32]
>>
It is following format of _MODULE_START_<module_name>. As I saw module name already at the end under [] so I removed the module name.

    > [53.795979] RSP: 0018:ffff9d602c707c40 EFLAGS: 00010286
    > [53.795980] RAX: 0000000000000047 RBX: ffff9d600b4c0800 RCX: 0000000000000006
    > [53.795980] RDX: 0000000000000007 RSI: 0000000000000096 RDI: ffff9d603fc172f0
    > [53.795981] RBP: 0000000000000000 R08: 00000000000004bd R09: 0000000000000002
    > [53.795981] R10: ffffffffc2250083 R11: 0000000000000001 R12: ffff9d5fb785a870
    > [53.795982] R13: 00000000fffffff4 R14: ffff9d5fb785a800 R15: 0000000000000000
    > [53.795983] FS:  00007ffb73c2ab80(0000) GS:ffff9d603fc00000(0000)
    > [53.795983] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
    > [53.795984] CR2: 00000000f76e6270 CR3: 0000000107c0c006 CR4: 00000000001606f0
    > [53.796014] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
    > [53.796014] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
    > [53.796015] Call Trace:
    > [53.796022]  ops_init.constprop.8+0x81/0x110
    > [53.796024]  register_pernet_operations+0x92/0xc0
    > [53.796026]  ? _MODULE_INIT_+0x393/0x393 [nfnetmap_queue]          <======
    > [53.796027]  register_pernet_subsys+0x1f/0x40
    > [53.796028]  init_module+0x51/0xc6d [nfnetmap_queue]
    > [53.796031]  do_one_initcall+0x36/0x160
    > 
    > 2. added a call to sprint_symbol in a module
    > ---------------------------------------------
    > $ decode for symbol nfnm_queue_flush+16:
    > _MODULE_START_+0x7e0/0x1daa [nfnetmap_queue]                       <======
    > 
    > $ nm nfnetmap_queue.ko | grep _flush
    > 00000000000007d0 t nfnm_queue_flush
    > 0x7d0 + 16d = 0x7e0 so this offset maps to symbol nfnm_queue_flush
    > 
    > tested on kernel 4.14.38
    > 
    > Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
    > ---
    >  kernel/module.c | 21 +++++++++++++++++----
    >  1 file changed, 17 insertions(+), 4 deletions(-)
    > 
    > diff --git a/kernel/module.c b/kernel/module.c
    > index 84a9141a5e15..d55fb8405151 100644
    > --- a/kernel/module.c
    > +++ b/kernel/module.c
    > @@ -4259,12 +4259,19 @@ static const char *find_kallsyms_symbol(struct module *mod,
    >         unsigned int i, best = 0;
    >         unsigned long nextval, bestval;
    >         struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
    > +       char *module_base_name = "_MODULE_START_";

    I don't think "_MODULE_START_" tells the user anything clear.
    If we're going to use heuristics best we use a nomenclature we
    can expand later and not be cryptic.

    So maybe just [module] is good enough.
Vimal>> As mentioned above, I just took reference from bt output of crash utility. Problem is some symbol will be from init section in module. So user needs to know if it belongs to core or init section of module so that it can be decoded manually later. We need some hint for user to suggest if it is part of init section or not.
Are you suggesting [module] for address in core section and [module __init] (with space between module and _init) for init section? 

    We don't have to initialize this as well, as its either one or the other.
Vimal>> yes. I will fix it.

    > +       unsigned long module_base_address = 0;
    > 
    >         /* At worse, next value is at end of module */
    > -       if (within_module_init(addr, mod))
    > +       if (within_module_init(addr, mod)) {
    >                 nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
    > -       else
    > +               module_base_address = (unsigned long)mod->init_layout.base;
    > +               module_base_name = "_MODULE_INIT_";
    > +       } else {
    >                 nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
    > +               module_base_address = (unsigned long)mod->core_layout.base;
    > +               module_base_name = "_MODULE_START_";
    > +       }
    > 
    >         bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
    > 
    > @@ -4295,8 +4302,14 @@ static const char *find_kallsyms_symbol(struct module *mod,
    >                         nextval = thisval;
    >         }
    > 
    > -       if (!best)
    > -               return NULL;
    > +       if (!best) {
    > +               /* return MODULE base and offset from it */
    > +               if (size)
    > +                       *size = nextval - module_base_address;
    > +               if (offset)
    > +                       *offset = addr - module_base_address;
    > +               return module_base_name;

    Have you tested this on recent kernels? If not please test this there
    as I cannot reproduce with your changes taking effect at all. In fact
    this branch is not hit at all.
Vimal>> No. I tested on kernel 4.14.173 only. I will test on latest kernel. Have you stripped the module using --strip-unneeded? I saw the code base for this function is same in latest vs 4.14.173 so I skipped the testing part on latest kernel. Will do that now.


      Luis


^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
  2021-12-09  5:37       ` Vimal Agrawal
@ 2021-12-09 20:40         ` Luis Chamberlain
  2021-12-20  8:57           ` Vimal Agrawal
  0 siblings, 1 reply; 36+ messages in thread
From: Luis Chamberlain @ 2021-12-09 20:40 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: Masahiro Yamada, Michal Marek, Nick Desaulniers, Jan Beulich,
	Jeff Mahoney, Sam Ravnborg, linux-kbuild, jeyu, linux-kernel

On Thu, Dec 09, 2021 at 05:37:48AM +0000, Vimal Agrawal wrote:
> Hi Luis,
> 
> My replies in-line under Vimal>>
> 
> Thanks,
> Vimal
> 
> -----Original Message-----
> From: Luis Chamberlain <mcgrof@infradead.org> on behalf of Luis Chamberlain <mcgrof@kernel.org>
> Date: Thursday, 9 December 2021 at 1:03 AM
> To: Vimal Agrawal <Vimal.Agrawal@sophos.com>, Masahiro Yamada <masahiroy@kernel.org>, Michal Marek <michal.lkml@markovi.net>, Nick Desaulniers <ndesaulniers@google.com>, Jan Beulich <JBeulich@suse.com>, Jeff Mahoney <jeffm@suse.com>, Sam Ravnborg <sam@ravnborg.org>, "linux-kbuild@vger.kernel.org" <linux-kbuild@vger.kernel.org>
> Cc: "jeyu@kernel.org" <jeyu@kernel.org>, "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>
> Subject: Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
> 
>     Thanks for your patch! I will note to start off with that unfortunately
>     whatever it is you use to send emails leaves them with UTF encodings
>     which does not let me easily download the patches using lore. For
>     instance, this is what I see:
> 
>     https://lore.kernel.org/all/106F23FD-3768-4CF0-893D-EDFE4A0BA2BF@sophos.com/raw
> 
>     Here is an example of a good patch:
> 
>     https://lore.kernel.org/all/20211129034509.2646872-2-ming.lei@redhat.com/raw
> 
>     What are you using to send patches? Consider using git send-email.
>     I think your mailer is sending the emails out as MIME attachments.
> Vimal>> I am using outlook app on mac and I changed format to use "plain format text". I will use git send-email from next time for patches.
> Thanks for letting me know.

Oh my. Even your replies do not follow typical development style best
practices. I recommend trying a Mail User Agent like mutt or anything
that can let you reply bottom style, please read:

https://en.wikipedia.org/wiki/Posting_style#Bottom-posting

Your MUA setting for "plain fomat text" seems to have lied.

If you really want a GUI for a MUA, consider Thunderbird.
I am not sure what other ones to recommend for the Mac.

>     On Mon, Nov 22, 2021 at 02:02:30PM +0000, Vimal Agrawal wrote:
>     > If kernel modules are stripped off symbols (say built by using strip --
>     > strip-unneeded)
> 
>     OK so is your build system using something like:
> 
>     make install modules_install INSTALL_MOD_STRIP="--strip-unneeded"
> 
>     At least that's one way to strip modules using upstream techniques since
>     the 2.6 kernel days. Because it would be wise for us to document *how* to
>     reproduce the issue you are seeing in your commit log.
> Vimal>> yes, our build uses INSTALL_MOD_STRIP="--strip-unneeded"

Ok great the commit log should indicate this.

>     > then stack traces in dmesg do not show module name or
>     > symbol name for addresses.
> 
>     as intended. So there is actually no issue and your patch is not a fix.
>     It is an optimization to help readers with a hint. So if we get anywhere
>     with this patch I'd say change the subject to relate it to
>     a heuristic enhancement for INSTALL_MOD_STRIP when --strip-unneeded is used.
> Vimal>> yes, problem is only when --strip-unneeded option is used to strip the modules.

It is not a problem, it is by design.

>     > It just prints absolute address ( without any
>     > reference of module)
>     > e.g.
>     > 
>     > [245864.699580]  do_nmi+0x12f/0x370
>     > [245864.699583]  end_repeat_nmi+0x16/0x50
>     > [245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
>     > [245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
>     > [245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
>     > [245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
>     > [245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
>     > [245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
>     > [245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
>     > [245864.699590]  ? 0xffffffffc06b61a0
>     > [245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
>     > [245864.699593]  ? 0xffffffffc06b67ec
>     > [245864.699594]  </NMI>
>     > 
>     > Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
>     > stack trace as absolute address.
>     > There is no easy way in case box crashes as we loose /proc/modules to see
>     > load address of modules to map address to one specific module. It will be
>     > really good to give some hint of module and offset inside module section
>     > about such addresses.
>     > 
>     > so changed kernel/module.c so that it can decode address to _MODULE_START_+
>     > offset/size or _MODULE_INIT_+offset/size depending on where the address
>     > lies (in core/.text or init/.init.text section of module).
>     > 
>     > e.g. nfnm_queue_net_init+0x2f1/0x393 [nfnetmap_queue] printed in case of
>     > symbols present shows up as 0010:0xffffffffc06b67ec in case symbols are
>     > absent. With modified logic, it will be shown as _MODULE_INIT_+0x2f1/0x393
>     > [nfnetmap_queue]
>     > 
>     > This will help for developer to debug and map this to actual nfnm_queue_net
>     > _init symbol later. One can use objdump/readelf/nm to find symbols with
>     > offset in .init.text and .text sections.
>     > 
>     > tests done:
>     > ===========
>     > 1. added WARN_ON_ONE(1) in init_module of a module
>     > ----------------------------------------------------
>     > [53.795977] task: ffff9d60094b3000 task.stack: ffff9d602c704000
>     > [53.795978] RIP: 0010:_MODULE_INIT_+0x2f1/0x393 [nfnetmap_queue]   <=====
> 
>     Huh, if the module is already printed (the [nfnetmap_queue]) why even
>     have _MODULE_INIT_ and instead we just say:
> 
>     [53.795978] RIP: 0010:[module __init]+0x2f1/0x393 [nfnetmap_queue]
> 
>     This way if you come up with other heuristics this can also be put in
>     the [] and we'd document that.
>
> Vimal>> I am fine with that. I used _MODULE_INIT_ and _MODULE_START_
> because I see something similar being reported by bt command in crash
> utility in these cases.  So I took reference of that. See following bt
> from crash utility: <<

Oh boy reading your replies is really difficult. Please please use an
MUA that lets you reply using bottom style, don't do the Vimal>> thing
and instead use the ">" and levels of that to imply what was said last.
The wikipedia article has examples of that and you can see other
mailing list exchanges for how this is done. Also don't make long lines.

> #6 [ffff99cdc059b8c0] _MODULE_START_act_mirred at ffffffffc06cd7ee [act_mirred]
>  #7 [ffff99cdc059b900] tcf_action_exec at ffffffff864c57bc
>  #8 [ffff99cdc059b948] _MODULE_START_cls_u32 at ffffffffc06d2620 [cls_u32]

Ah, intersting, then it is something to consider.

Can you find the commit for crash bt that added that heuristic? I'm
curious to see why they opted for _MODULE_START.

> It is following format of _MODULE_START_<module_name>. As I saw module name already at the end under [] so I removed the module name.
> 
>     > [53.795979] RSP: 0018:ffff9d602c707c40 EFLAGS: 00010286
>     > [53.795980] RAX: 0000000000000047 RBX: ffff9d600b4c0800 RCX: 0000000000000006
>     > [53.795980] RDX: 0000000000000007 RSI: 0000000000000096 RDI: ffff9d603fc172f0
>     > [53.795981] RBP: 0000000000000000 R08: 00000000000004bd R09: 0000000000000002
>     > [53.795981] R10: ffffffffc2250083 R11: 0000000000000001 R12: ffff9d5fb785a870
>     > [53.795982] R13: 00000000fffffff4 R14: ffff9d5fb785a800 R15: 0000000000000000
>     > [53.795983] FS:  00007ffb73c2ab80(0000) GS:ffff9d603fc00000(0000)
>     > [53.795983] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>     > [53.795984] CR2: 00000000f76e6270 CR3: 0000000107c0c006 CR4: 00000000001606f0
>     > [53.796014] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
>     > [53.796014] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
>     > [53.796015] Call Trace:
>     > [53.796022]  ops_init.constprop.8+0x81/0x110
>     > [53.796024]  register_pernet_operations+0x92/0xc0
>     > [53.796026]  ? _MODULE_INIT_+0x393/0x393 [nfnetmap_queue]          <======
>     > [53.796027]  register_pernet_subsys+0x1f/0x40
>     > [53.796028]  init_module+0x51/0xc6d [nfnetmap_queue]
>     > [53.796031]  do_one_initcall+0x36/0x160
>     > 
>     > 2. added a call to sprint_symbol in a module
>     > ---------------------------------------------
>     > $ decode for symbol nfnm_queue_flush+16:
>     > _MODULE_START_+0x7e0/0x1daa [nfnetmap_queue]                       <======
>     > 
>     > $ nm nfnetmap_queue.ko | grep _flush
>     > 00000000000007d0 t nfnm_queue_flush
>     > 0x7d0 + 16d = 0x7e0 so this offset maps to symbol nfnm_queue_flush
>     > 
>     > tested on kernel 4.14.38
>     > 
>     > Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
>     > ---
>     >  kernel/module.c | 21 +++++++++++++++++----
>     >  1 file changed, 17 insertions(+), 4 deletions(-)
>     > 
>     > diff --git a/kernel/module.c b/kernel/module.c
>     > index 84a9141a5e15..d55fb8405151 100644
>     > --- a/kernel/module.c
>     > +++ b/kernel/module.c
>     > @@ -4259,12 +4259,19 @@ static const char *find_kallsyms_symbol(struct module *mod,
>     >         unsigned int i, best = 0;
>     >         unsigned long nextval, bestval;
>     >         struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
>     > +       char *module_base_name = "_MODULE_START_";
> 
>     I don't think "_MODULE_START_" tells the user anything clear.
>     If we're going to use heuristics best we use a nomenclature we
>     can expand later and not be cryptic.
> 
>     So maybe just [module] is good enough.
> Vimal>> As mentioned above, I just took reference from bt output of crash utility. Problem is some symbol will be from init section in module. So user needs to know if it belongs to core or init section of module so that it can be decoded manually later. We need some hint for user to suggest if it is part of init section or not.
> Are you suggesting [module] for address in core section and [module __init] (with space between module and _init) for init section? 

Yes my suggestion was:

[module]
[module __init]

I think that implies a heuristic with the brackets and the rest is
pretty self explanatory. _MODULE_START_ seems cryptic. But I'm curious
why crash bt went with that. So if you can look into that it would be
appreciated.

>     We don't have to initialize this as well, as its either one or the other.
> Vimal>> yes. I will fix it.
> 
>     > +       unsigned long module_base_address = 0;
>     > 
>     >         /* At worse, next value is at end of module */
>     > -       if (within_module_init(addr, mod))
>     > +       if (within_module_init(addr, mod)) {
>     >                 nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
>     > -       else
>     > +               module_base_address = (unsigned long)mod->init_layout.base;
>     > +               module_base_name = "_MODULE_INIT_";
>     > +       } else {
>     >                 nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
>     > +               module_base_address = (unsigned long)mod->core_layout.base;
>     > +               module_base_name = "_MODULE_START_";
>     > +       }
>     > 
>     >         bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
>     > 
>     > @@ -4295,8 +4302,14 @@ static const char *find_kallsyms_symbol(struct module *mod,
>     >                         nextval = thisval;
>     >         }
>     > 
>     > -       if (!best)
>     > -               return NULL;
>     > +       if (!best) {
>     > +               /* return MODULE base and offset from it */
>     > +               if (size)
>     > +                       *size = nextval - module_base_address;
>     > +               if (offset)
>     > +                       *offset = addr - module_base_address;
>     > +               return module_base_name;
> 
>     Have you tested this on recent kernels? If not please test this there
>     as I cannot reproduce with your changes taking effect at all. In fact
>     this branch is not hit at all.
> Vimal>> No. I tested on kernel 4.14.173 only. I will test on latest kernel. Have you stripped the module using --strip-unneeded? I saw the code base for this function is same in latest vs 4.14.173 so I skipped the testing part on latest kernel. Will do that now.
> 

Please test with linux-next. Your patch should be based on linux-next as
well. You can test your stuff by adding a WARN_ON_ONCE(1) to
lib/test_module.c

  Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
  2021-12-09 20:40         ` Luis Chamberlain
@ 2021-12-20  8:57           ` Vimal Agrawal
  2021-12-20 19:21             ` Luis Chamberlain
  0 siblings, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2021-12-20  8:57 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Masahiro Yamada, Michal Marek, Nick Desaulniers, Jan Beulich,
	Jeff Mahoney, Sam Ravnborg, linux-kbuild, jeyu, linux-kernel,
	Vimal Agrawal

Hi Luis,

Sorry for goof up with inline replies. I found that gmail supports bottom-posting so I will be replying inline from gmail next time. I will send the next patch using git send-email.

Looks like it has been there in crash source for very long.

store_module_symbols_v2
        sprintf(buf2, "%s%s", "_MODULE_START_", mod_name);
            sprintf(buf3, "%s%s", "_MODULE_INIT_START_", mod_name);

I will test it first on latest ubuntu which has kernel version 5.13.0-22.

Vimal

-----Original Message-----
From: Luis Chamberlain <mcgrof@infradead.org> on behalf of Luis Chamberlain <mcgrof@kernel.org>
Date: Friday, 10 December 2021 at 2:10 AM
To: Vimal Agrawal <Vimal.Agrawal@sophos.com>
Cc: Masahiro Yamada <masahiroy@kernel.org>, Michal Marek <michal.lkml@markovi.net>, Nick Desaulniers <ndesaulniers@google.com>, Jan Beulich <JBeulich@suse.com>, Jeff Mahoney <jeffm@suse.com>, Sam Ravnborg <sam@ravnborg.org>, "linux-kbuild@vger.kernel.org" <linux-kbuild@vger.kernel.org>, "jeyu@kernel.org" <jeyu@kernel.org>, "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>
Subject: Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules

    On Thu, Dec 09, 2021 at 05:37:48AM +0000, Vimal Agrawal wrote:
    > Hi Luis,
    > 
    > My replies in-line under Vimal>>
    > 
    > Thanks,
    > Vimal
    > 
    > -----Original Message-----
    > From: Luis Chamberlain <mcgrof@infradead.org> on behalf of Luis Chamberlain <mcgrof@kernel.org>
    > Date: Thursday, 9 December 2021 at 1:03 AM
    > To: Vimal Agrawal <Vimal.Agrawal@sophos.com>, Masahiro Yamada <masahiroy@kernel.org>, Michal Marek <michal.lkml@markovi.net>, Nick Desaulniers <ndesaulniers@google.com>, Jan Beulich <JBeulich@suse.com>, Jeff Mahoney <jeffm@suse.com>, Sam Ravnborg <sam@ravnborg.org>, "linux-kbuild@vger.kernel.org" <linux-kbuild@vger.kernel.org>
    > Cc: "jeyu@kernel.org" <jeyu@kernel.org>, "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>
    > Subject: Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
    > 
    >     Thanks for your patch! I will note to start off with that unfortunately
    >     whatever it is you use to send emails leaves them with UTF encodings
    >     which does not let me easily download the patches using lore. For
    >     instance, this is what I see:
    > 
    >     https://lore.kernel.org/all/106F23FD-3768-4CF0-893D-EDFE4A0BA2BF@sophos.com/raw
    > 
    >     Here is an example of a good patch:
    > 
    >     https://lore.kernel.org/all/20211129034509.2646872-2-ming.lei@redhat.com/raw
    > 
    >     What are you using to send patches? Consider using git send-email.
    >     I think your mailer is sending the emails out as MIME attachments.
    > Vimal>> I am using outlook app on mac and I changed format to use "plain format text". I will use git send-email from next time for patches.
    > Thanks for letting me know.

    Oh my. Even your replies do not follow typical development style best
    practices. I recommend trying a Mail User Agent like mutt or anything
    that can let you reply bottom style, please read:

    https://en.wikipedia.org/wiki/Posting_style#Bottom-posting

    Your MUA setting for "plain fomat text" seems to have lied.

    If you really want a GUI for a MUA, consider Thunderbird.
    I am not sure what other ones to recommend for the Mac.

    >     On Mon, Nov 22, 2021 at 02:02:30PM +0000, Vimal Agrawal wrote:
    >     > If kernel modules are stripped off symbols (say built by using strip --
    >     > strip-unneeded)
    > 
    >     OK so is your build system using something like:
    > 
    >     make install modules_install INSTALL_MOD_STRIP="--strip-unneeded"
    > 
    >     At least that's one way to strip modules using upstream techniques since
    >     the 2.6 kernel days. Because it would be wise for us to document *how* to
    >     reproduce the issue you are seeing in your commit log.
    > Vimal>> yes, our build uses INSTALL_MOD_STRIP="--strip-unneeded"

    Ok great the commit log should indicate this.

    >     > then stack traces in dmesg do not show module name or
    >     > symbol name for addresses.
    > 
    >     as intended. So there is actually no issue and your patch is not a fix.
    >     It is an optimization to help readers with a hint. So if we get anywhere
    >     with this patch I'd say change the subject to relate it to
    >     a heuristic enhancement for INSTALL_MOD_STRIP when --strip-unneeded is used.
    > Vimal>> yes, problem is only when --strip-unneeded option is used to strip the modules.

    It is not a problem, it is by design.

    >     > It just prints absolute address ( without any
    >     > reference of module)
    >     > e.g.
    >     > 
    >     > [245864.699580]  do_nmi+0x12f/0x370
    >     > [245864.699583]  end_repeat_nmi+0x16/0x50
    >     > [245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
    >     > [245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
    >     > [245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
    >     > [245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
    >     > [245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
    >     > [245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
    >     > [245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
    >     > [245864.699590]  ? 0xffffffffc06b61a0
    >     > [245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
    >     > [245864.699593]  ? 0xffffffffc06b67ec
    >     > [245864.699594]  </NMI>
    >     > 
    >     > Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
    >     > stack trace as absolute address.
    >     > There is no easy way in case box crashes as we loose /proc/modules to see
    >     > load address of modules to map address to one specific module. It will be
    >     > really good to give some hint of module and offset inside module section
    >     > about such addresses.
    >     > 
    >     > so changed kernel/module.c so that it can decode address to _MODULE_START_+
    >     > offset/size or _MODULE_INIT_+offset/size depending on where the address
    >     > lies (in core/.text or init/.init.text section of module).
    >     > 
    >     > e.g. nfnm_queue_net_init+0x2f1/0x393 [nfnetmap_queue] printed in case of
    >     > symbols present shows up as 0010:0xffffffffc06b67ec in case symbols are
    >     > absent. With modified logic, it will be shown as _MODULE_INIT_+0x2f1/0x393
    >     > [nfnetmap_queue]
    >     > 
    >     > This will help for developer to debug and map this to actual nfnm_queue_net
    >     > _init symbol later. One can use objdump/readelf/nm to find symbols with
    >     > offset in .init.text and .text sections.
    >     > 
    >     > tests done:
    >     > ===========
    >     > 1. added WARN_ON_ONE(1) in init_module of a module
    >     > ----------------------------------------------------
    >     > [53.795977] task: ffff9d60094b3000 task.stack: ffff9d602c704000
    >     > [53.795978] RIP: 0010:_MODULE_INIT_+0x2f1/0x393 [nfnetmap_queue]   <=====
    > 
    >     Huh, if the module is already printed (the [nfnetmap_queue]) why even
    >     have _MODULE_INIT_ and instead we just say:
    > 
    >     [53.795978] RIP: 0010:[module __init]+0x2f1/0x393 [nfnetmap_queue]
    > 
    >     This way if you come up with other heuristics this can also be put in
    >     the [] and we'd document that.
    >
    > Vimal>> I am fine with that. I used _MODULE_INIT_ and _MODULE_START_
    > because I see something similar being reported by bt command in crash
    > utility in these cases.  So I took reference of that. See following bt
    > from crash utility: <<

    Oh boy reading your replies is really difficult. Please please use an
    MUA that lets you reply using bottom style, don't do the Vimal>> thing
    and instead use the ">" and levels of that to imply what was said last.
    The wikipedia article has examples of that and you can see other
    mailing list exchanges for how this is done. Also don't make long lines.

    > #6 [ffff99cdc059b8c0] _MODULE_START_act_mirred at ffffffffc06cd7ee [act_mirred]
    >  #7 [ffff99cdc059b900] tcf_action_exec at ffffffff864c57bc
    >  #8 [ffff99cdc059b948] _MODULE_START_cls_u32 at ffffffffc06d2620 [cls_u32]

    Ah, intersting, then it is something to consider.

    Can you find the commit for crash bt that added that heuristic? I'm
    curious to see why they opted for _MODULE_START.

    > It is following format of _MODULE_START_<module_name>. As I saw module name already at the end under [] so I removed the module name.
    > 
    >     > [53.795979] RSP: 0018:ffff9d602c707c40 EFLAGS: 00010286
    >     > [53.795980] RAX: 0000000000000047 RBX: ffff9d600b4c0800 RCX: 0000000000000006
    >     > [53.795980] RDX: 0000000000000007 RSI: 0000000000000096 RDI: ffff9d603fc172f0
    >     > [53.795981] RBP: 0000000000000000 R08: 00000000000004bd R09: 0000000000000002
    >     > [53.795981] R10: ffffffffc2250083 R11: 0000000000000001 R12: ffff9d5fb785a870
    >     > [53.795982] R13: 00000000fffffff4 R14: ffff9d5fb785a800 R15: 0000000000000000
    >     > [53.795983] FS:  00007ffb73c2ab80(0000) GS:ffff9d603fc00000(0000)
    >     > [53.795983] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
    >     > [53.795984] CR2: 00000000f76e6270 CR3: 0000000107c0c006 CR4: 00000000001606f0
    >     > [53.796014] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
    >     > [53.796014] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
    >     > [53.796015] Call Trace:
    >     > [53.796022]  ops_init.constprop.8+0x81/0x110
    >     > [53.796024]  register_pernet_operations+0x92/0xc0
    >     > [53.796026]  ? _MODULE_INIT_+0x393/0x393 [nfnetmap_queue]          <======
    >     > [53.796027]  register_pernet_subsys+0x1f/0x40
    >     > [53.796028]  init_module+0x51/0xc6d [nfnetmap_queue]
    >     > [53.796031]  do_one_initcall+0x36/0x160
    >     > 
    >     > 2. added a call to sprint_symbol in a module
    >     > ---------------------------------------------
    >     > $ decode for symbol nfnm_queue_flush+16:
    >     > _MODULE_START_+0x7e0/0x1daa [nfnetmap_queue]                       <======
    >     > 
    >     > $ nm nfnetmap_queue.ko | grep _flush
    >     > 00000000000007d0 t nfnm_queue_flush
    >     > 0x7d0 + 16d = 0x7e0 so this offset maps to symbol nfnm_queue_flush
    >     > 
    >     > tested on kernel 4.14.38
    >     > 
    >     > Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
    >     > ---
    >     >  kernel/module.c | 21 +++++++++++++++++----
    >     >  1 file changed, 17 insertions(+), 4 deletions(-)
    >     > 
    >     > diff --git a/kernel/module.c b/kernel/module.c
    >     > index 84a9141a5e15..d55fb8405151 100644
    >     > --- a/kernel/module.c
    >     > +++ b/kernel/module.c
    >     > @@ -4259,12 +4259,19 @@ static const char *find_kallsyms_symbol(struct module *mod,
    >     >         unsigned int i, best = 0;
    >     >         unsigned long nextval, bestval;
    >     >         struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
    >     > +       char *module_base_name = "_MODULE_START_";
    > 
    >     I don't think "_MODULE_START_" tells the user anything clear.
    >     If we're going to use heuristics best we use a nomenclature we
    >     can expand later and not be cryptic.
    > 
    >     So maybe just [module] is good enough.
    > Vimal>> As mentioned above, I just took reference from bt output of crash utility. Problem is some symbol will be from init section in module. So user needs to know if it belongs to core or init section of module so that it can be decoded manually later. We need some hint for user to suggest if it is part of init section or not.
    > Are you suggesting [module] for address in core section and [module __init] (with space between module and _init) for init section? 

    Yes my suggestion was:

    [module]
    [module __init]

    I think that implies a heuristic with the brackets and the rest is
    pretty self explanatory. _MODULE_START_ seems cryptic. But I'm curious
    why crash bt went with that. So if you can look into that it would be
    appreciated.

    >     We don't have to initialize this as well, as its either one or the other.
    > Vimal>> yes. I will fix it.
    > 
    >     > +       unsigned long module_base_address = 0;
    >     > 
    >     >         /* At worse, next value is at end of module */
    >     > -       if (within_module_init(addr, mod))
    >     > +       if (within_module_init(addr, mod)) {
    >     >                 nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
    >     > -       else
    >     > +               module_base_address = (unsigned long)mod->init_layout.base;
    >     > +               module_base_name = "_MODULE_INIT_";
    >     > +       } else {
    >     >                 nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
    >     > +               module_base_address = (unsigned long)mod->core_layout.base;
    >     > +               module_base_name = "_MODULE_START_";
    >     > +       }
    >     > 
    >     >         bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
    >     > 
    >     > @@ -4295,8 +4302,14 @@ static const char *find_kallsyms_symbol(struct module *mod,
    >     >                         nextval = thisval;
    >     >         }
    >     > 
    >     > -       if (!best)
    >     > -               return NULL;
    >     > +       if (!best) {
    >     > +               /* return MODULE base and offset from it */
    >     > +               if (size)
    >     > +                       *size = nextval - module_base_address;
    >     > +               if (offset)
    >     > +                       *offset = addr - module_base_address;
    >     > +               return module_base_name;
    > 
    >     Have you tested this on recent kernels? If not please test this there
    >     as I cannot reproduce with your changes taking effect at all. In fact
    >     this branch is not hit at all.
    > Vimal>> No. I tested on kernel 4.14.173 only. I will test on latest kernel. Have you stripped the module using --strip-unneeded? I saw the code base for this function is same in latest vs 4.14.173 so I skipped the testing part on latest kernel. Will do that now.
    > 

    Please test with linux-next. Your patch should be based on linux-next as
    well. You can test your stuff by adding a WARN_ON_ONCE(1) to
    lib/test_module.c

      Luis


^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
  2021-12-20  8:57           ` Vimal Agrawal
@ 2021-12-20 19:21             ` Luis Chamberlain
  2021-12-21  9:06               ` Vimal Agrawal
  0 siblings, 1 reply; 36+ messages in thread
From: Luis Chamberlain @ 2021-12-20 19:21 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: Masahiro Yamada, Michal Marek, Nick Desaulniers, Jan Beulich,
	Jeff Mahoney, Sam Ravnborg, linux-kbuild, jeyu, linux-kernel,
	Vimal Agrawal

On Mon, Dec 20, 2021 at 08:57:46AM +0000, Vimal Agrawal wrote:
> Hi Luis,
> 
> Sorry for goof up with inline replies. I found that gmail supports bottom-posting so I will be replying inline from gmail next time. I will send the next patch using git send-email.
> 
> Looks like it has been there in crash source for very long.
> 
> store_module_symbols_v2
>         sprintf(buf2, "%s%s", "_MODULE_START_", mod_name);
>             sprintf(buf3, "%s%s", "_MODULE_INIT_START_", mod_name);

Can you point to the commit that added it? Preferably if you can have
a URL I can just use to see the change?

> I will test it first on latest ubuntu which has kernel version 5.13.0-22.

No, that's not sufficient, I really want you to use either Linus' latest
tree or linux-next.

  Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
  2021-12-20 19:21             ` Luis Chamberlain
@ 2021-12-21  9:06               ` Vimal Agrawal
  2021-12-21 17:16                 ` Vimal Agrawal
  2021-12-21 22:46                 ` Luis Chamberlain
  0 siblings, 2 replies; 36+ messages in thread
From: Vimal Agrawal @ 2021-12-21  9:06 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Vimal Agrawal, Masahiro Yamada, Michal Marek, Nick Desaulniers,
	Jan Beulich, Jeff Mahoney, Sam Ravnborg, linux-kbuild, jeyu,
	linux-kernel

Hi Luis,

Please see https://github.com/crash-utility/crash/commit/03e3937ec7d1b356039433137cc6e531379ca454
( function store_module_symbols_v2  in file symbols.c). This was one
of the initial commit for crash utility.

I will work on linux-next and update you.

Vimal

On Tue, Dec 21, 2021 at 12:51 AM Luis Chamberlain <mcgrof@kernel.org> wrote:
>
> On Mon, Dec 20, 2021 at 08:57:46AM +0000, Vimal Agrawal wrote:
> > Hi Luis,
> >
> > Sorry for goof up with inline replies. I found that gmail supports bottom-posting so I will be replying inline from gmail next time. I will send the next patch using git send-email.
> >
> > Looks like it has been there in crash source for very long.
> >
> > store_module_symbols_v2
> >         sprintf(buf2, "%s%s", "_MODULE_START_", mod_name);
> >             sprintf(buf3, "%s%s", "_MODULE_INIT_START_", mod_name);
>
> Can you point to the commit that added it? Preferably if you can have
> a URL I can just use to see the change?
>
> > I will test it first on latest ubuntu which has kernel version 5.13.0-22.
>
> No, that's not sufficient, I really want you to use either Linus' latest
> tree or linux-next.
>
>   Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
  2021-12-21  9:06               ` Vimal Agrawal
@ 2021-12-21 17:16                 ` Vimal Agrawal
  2021-12-21 22:45                   ` Luis Chamberlain
  2021-12-21 22:46                 ` Luis Chamberlain
  1 sibling, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2021-12-21 17:16 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Vimal Agrawal, Masahiro Yamada, Michal Marek, Nick Desaulniers,
	Jan Beulich, Jeff Mahoney, Sam Ravnborg, linux-kbuild, jeyu,
	linux-kernel

Hi Luis,

I tried on linux->next (tag next-20211220). I am able to reproduce
problem with .init.text symbol with following test patch in
lib/test_module.c:

diff --git a/lib/test_module.c b/lib/test_module.c

index debd19e35198..ca7ff49dec14 100644

--- a/lib/test_module.c

+++ b/lib/test_module.c

@@ -14,10 +14,35 @@

 #include <linux/module.h>

 #include <linux/printk.h>



+int g_x=1;

+struct init_struct {

+    void (*init)(int);

+    void (*start)(int);

+};

+

+

+static void test_module_warn_start(int x)

+{

+        if (x) WARN_ON_ONCE(1);

+}

+

+static void __init test_module_warn_init(int x)

+{

+        if (x) WARN_ON_ONCE(1);

+}

+

+

+static struct init_struct my_init_struct = {

+.init = test_module_warn_init,

+.start = test_module_warn_start,

+};

+

+

 static int __init test_module_init(void)

 {

        pr_warn("Hello, world\n");

-

+       my_init_struct.init(1);

+       /* my_init_struct.start(1); */

        return 0;

 }

register dump in dmesg shows:

[10585.879220] CPU: 0 PID: 31999 Comm: insmod Tainted: G        W   E
   5.16.0-rc5-next-20211220 #1

[10585.879223] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS
VirtualBox 12/01/2006

[10585.879225] RIP: 0010:0xffffffffc0363004

[10585.879230] Code: Unable to access opcode bytes at RIP 0xffffffffc0362fda.

[10585.879231] RSP: 0018:ffffad6443247bb0 EFLAGS: 00010202

[10585.879234] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000

[10585.879236] RDX: 0000000000000000 RSI: ffffffffa538e589 RDI: 0000000000000001

[10585.879238] RBP: ffffad6443247bb8 R08: 0000000000000000 R09: ffffad64432479b0

[10585.879239] R10: ffffad64432479a8 R11: ffffffffa5755248 R12: ffffffffc0363007

[10585.879241] R13: ffff8b5be9b35340 R14: 0000000000000000 R15: 0000000000000000

[10585.879243] FS:  00007fb7c60f4400(0000) GS:ffff8b5cc0e00000(0000)
knlGS:0000000000000000

[10585.879246] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033

[10585.879247] CR2: ffffffffc0362fda CR3: 000000005c8c0005 CR4: 00000000000706f0

note that it could not decode RIP ( i.e. 0010:0xffffffffc0363004)

I am not able to reproduce the same with .text symbol consistently but
I remember I was able to reproduce it yesterday. It is kind of
dependent on the way symbols are generated based on code.

steps to repro :
1. patch test_module.c with above patch
2. build module using > make lib/test_module.ko
3. strip it using > strip --strip-unneeded test_module.ko
4. load it using insmod
5. check register dump in dmesg

Note that I did this test on vanilla kernel without my fix and I have
not tested it with my fix yet.

but I found another problem while I was trying this.

with few changes, I could see that it is decoding .text address
against the .init.text symbol. See following:

[ 9288.523510] address of init_module is ffffffffc0363000
[ 9288.523802] address of test_module_warn_start is ffffffffc0615000
[ 9288.523857] RIP: 0010:init_module+0x2b201e/0x2b2023 [test_module]

init_module is in .init.text and test_module_warn_start is in .text.
This looks wrong to me ( see big offset from the symbol i.e.
init_module+0x2b201e). It should decode the address to the symbol in
same elf section. Someone who is looking at dmesg is interested in
offset from some symbol in the same sections as sections are loaded at
different addresses in memory.
I think there should be a check in find_kallsyms_symbol to ignore
symbols from other sections when we are trying to decode an address to
a symbol.
or start with bestval from same section instead of starting with first symbol

find_kallsyms_symbol::
...
bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
...

Not sure if I am missing something here.

Vimal


On Tue, Dec 21, 2021 at 2:36 PM Vimal Agrawal <avimalin@gmail.com> wrote:
>
> Hi Luis,
>
> Please see https://github.com/crash-utility/crash/commit/03e3937ec7d1b356039433137cc6e531379ca454
> ( function store_module_symbols_v2  in file symbols.c). This was one
> of the initial commit for crash utility.
>
> I will work on linux-next and update you.
>
> Vimal
>
> On Tue, Dec 21, 2021 at 12:51 AM Luis Chamberlain <mcgrof@kernel.org> wrote:
> >
> > On Mon, Dec 20, 2021 at 08:57:46AM +0000, Vimal Agrawal wrote:
> > > Hi Luis,
> > >
> > > Sorry for goof up with inline replies. I found that gmail supports bottom-posting so I will be replying inline from gmail next time. I will send the next patch using git send-email.
> > >
> > > Looks like it has been there in crash source for very long.
> > >
> > > store_module_symbols_v2
> > >         sprintf(buf2, "%s%s", "_MODULE_START_", mod_name);
> > >             sprintf(buf3, "%s%s", "_MODULE_INIT_START_", mod_name);
> >
> > Can you point to the commit that added it? Preferably if you can have
> > a URL I can just use to see the change?
> >
> > > I will test it first on latest ubuntu which has kernel version 5.13.0-22.
> >
> > No, that's not sufficient, I really want you to use either Linus' latest
> > tree or linux-next.
> >
> >   Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
  2021-12-21 17:16                 ` Vimal Agrawal
@ 2021-12-21 22:45                   ` Luis Chamberlain
  0 siblings, 0 replies; 36+ messages in thread
From: Luis Chamberlain @ 2021-12-21 22:45 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: Vimal Agrawal, Masahiro Yamada, Michal Marek, Nick Desaulniers,
	Jan Beulich, Jeff Mahoney, Sam Ravnborg, linux-kbuild, jeyu,
	linux-kernel

On Tue, Dec 21, 2021 at 10:46:37PM +0530, Vimal Agrawal wrote:
> Hi Luis,
> 
> I tried on linux->next (tag next-20211220). I am able to reproduce
> problem with .init.text symbol with following test patch in
> lib/test_module.c:
> 
> diff --git a/lib/test_module.c b/lib/test_module.c

Your mailer is still making things odd:

> 
> index debd19e35198..ca7ff49dec14 100644
> 
> --- a/lib/test_module.c
> 
> +++ b/lib/test_module.c
> 
> @@ -14,10 +14,35 @@

It adds new lines where it is not needed.

> 
>  #include <linux/module.h>
> 
>  #include <linux/printk.h>
> 
> 
> 
> +int g_x=1;
> 
> +struct init_struct {
> 
> +    void (*init)(int);
> 
> +    void (*start)(int);
> 
> +};
> 
> +
> 
> +
> 
> +static void test_module_warn_start(int x)
> 
> +{
> 
> +        if (x) WARN_ON_ONCE(1);
> 
> +}
> 
> +
> 
> +static void __init test_module_warn_init(int x)
> 
> +{
> 
> +        if (x) WARN_ON_ONCE(1);
> 
> +}
> 
> +
> 
> +
> 
> +static struct init_struct my_init_struct = {
> 
> +.init = test_module_warn_init,
> 
> +.start = test_module_warn_start,
> 
> +};
> 
> +
> 
> +
> 
>  static int __init test_module_init(void)
> 
>  {
> 
>         pr_warn("Hello, world\n");
> 
> -
> 
> +       my_init_struct.init(1);
> 
> +       /* my_init_struct.start(1); */
> 
>         return 0;
> 
>  }
> 
> register dump in dmesg shows:
> 
> [10585.879220] CPU: 0 PID: 31999 Comm: insmod Tainted: G        W   E
>    5.16.0-rc5-next-20211220 #1
> 
> [10585.879223] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS
> VirtualBox 12/01/2006
> 
> [10585.879225] RIP: 0010:0xffffffffc0363004
> 
> [10585.879230] Code: Unable to access opcode bytes at RIP 0xffffffffc0362fda.
> 
> [10585.879231] RSP: 0018:ffffad6443247bb0 EFLAGS: 00010202
> 
> [10585.879234] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> 
> [10585.879236] RDX: 0000000000000000 RSI: ffffffffa538e589 RDI: 0000000000000001
> 
> [10585.879238] RBP: ffffad6443247bb8 R08: 0000000000000000 R09: ffffad64432479b0
> 
> [10585.879239] R10: ffffad64432479a8 R11: ffffffffa5755248 R12: ffffffffc0363007
> 
> [10585.879241] R13: ffff8b5be9b35340 R14: 0000000000000000 R15: 0000000000000000
> 
> [10585.879243] FS:  00007fb7c60f4400(0000) GS:ffff8b5cc0e00000(0000)
> knlGS:0000000000000000
> 
> [10585.879246] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> 
> [10585.879247] CR2: ffffffffc0362fda CR3: 000000005c8c0005 CR4: 00000000000706f0
> 
> note that it could not decode RIP ( i.e. 0010:0xffffffffc0363004)
> 
> I am not able to reproduce the same with .text symbol consistently but
> I remember I was able to reproduce it yesterday. It is kind of
> dependent on the way symbols are generated based on code.
> 
> steps to repro :
> 1. patch test_module.c with above patch
> 2. build module using > make lib/test_module.ko
> 3. strip it using > strip --strip-unneeded test_module.ko
> 4. load it using insmod
> 5. check register dump in dmesg

OK with out your patch yes obviously things are opaque.

> 
> Note that I did this test on vanilla kernel without my fix and I have
> not tested it with my fix yet.

Please stop calling your changes a fix. It is not a fix. It is adding
new heuristics.

And not sure I follow. I just want you to focus on linux-next.

> but I found another problem while I was trying this.
> 
> with few changes, I could see that it is decoding .text address
> against the .init.text symbol. See following:
> 
> [ 9288.523510] address of init_module is ffffffffc0363000
> [ 9288.523802] address of test_module_warn_start is ffffffffc0615000
> [ 9288.523857] RIP: 0010:init_module+0x2b201e/0x2b2023 [test_module]
> 
> init_module is in .init.text and test_module_warn_start is in .text.
> This looks wrong to me ( see big offset from the symbol i.e.
> init_module+0x2b201e). It should decode the address to the symbol in
> same elf section. Someone who is looking at dmesg is interested in
> offset from some symbol in the same sections as sections are loaded at
> different addresses in memory.
> I think there should be a check in find_kallsyms_symbol to ignore
> symbols from other sections when we are trying to decode an address to
> a symbol.
> or start with bestval from same section instead of starting with first symbol
> 
> find_kallsyms_symbol::
> ...
> bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
> ...
> 
> Not sure if I am missing something here.

Please send a new patch with proper instructions there, so I can test.
The first patch didn't even make it to the archive as it was botched.

Also modify the commit log as I requested.

  Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules
  2021-12-21  9:06               ` Vimal Agrawal
  2021-12-21 17:16                 ` Vimal Agrawal
@ 2021-12-21 22:46                 ` Luis Chamberlain
  2021-12-22 13:23                   ` [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used Vimal Agrawal
  1 sibling, 1 reply; 36+ messages in thread
From: Luis Chamberlain @ 2021-12-21 22:46 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: Vimal Agrawal, Masahiro Yamada, Michal Marek, Nick Desaulniers,
	Jan Beulich, Jeff Mahoney, Sam Ravnborg, linux-kbuild, jeyu,
	linux-kernel

On Tue, Dec 21, 2021 at 02:36:48PM +0530, Vimal Agrawal wrote:
> Hi Luis,
> 
> Please see https://github.com/crash-utility/crash/commit/03e3937ec7d1b356039433137cc6e531379ca454
> ( function store_module_symbols_v2  in file symbols.c). This was one
> of the initial commit for crash utility.

OK then I see no good reason to follow that convetion.
I'd much prefer if we use our own and make it mean something a bit more
obvious and clear as I had suggested.

> I will work on linux-next and update you.

Great.

  Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2021-12-21 22:46                 ` Luis Chamberlain
@ 2021-12-22 13:23                   ` Vimal Agrawal
  2021-12-23 10:36                     ` Christoph Hellwig
  0 siblings, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2021-12-22 13:23 UTC (permalink / raw)
  To: mcgrof
  Cc: vimal.Agrawal, masahiroy, michal.lkml, ndesaulniers, JBeulich,
	jeffm, sam, linux-kbuild, jeyu, linux-kernel, avimalin,
	Vimal Agrawal

If kernel modules are stripped off symbols (e.g. built by using strip
--strip-unneeded option) then stack traces in dmesg do not show symbol
name for address. It just prints absolute address sometimes (if there
is no good match with any symbol)
e.g.

[245864.699580]  do_nmi+0x12f/0x370
[245864.699583]  end_repeat_nmi+0x16/0x50
[245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
[245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
[245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
[245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
[245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
[245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
[245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
[245864.699590]  ? 0xffffffffc06b61a0
[245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
[245864.699593]  ? 0xffffffffc06b67ec
[245864.699594]  </NMI>

Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
stack trace as absolute address.
There is no easy way in case box crashes as we loose information on load
address of specific module. This changes the symbol decoding (in kernel/
module.c) such that it can print offset from start of section (.text or
.init.text) in case there is no good match with any symbol.

It will now decode address in such cases to [module]+ offset/size or
[module __init]+offset/size depending on where the address lies (in
core/.text or init/.init.text section of module).

One can use objdump/readelf/nm to find symbols with offset from
.init.text and .text sections.

steps to reproduce the problem:
-------------------------------
1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
2. Build and strip the module using --strip-unneeded option
3. Load the module and check RIP in dmesg

tests done:
-----------
1. Added WARN_ON_ONE(1) in functions of a module for testing
-------------------------------------------------------------
[  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
[  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  407.934089] returning module_base_name: [module __init]
[  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
[  407.934092] returning module_base_name: [module __init]
[  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
[  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
[  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
[  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
[  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
[  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
[  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
[  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
[  407.934113] Call Trace:
[  407.934114]  <TASK>
[  407.934116]  ? init_module+0x55/0xff9 [test_module]
...
[  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
[  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  407.934242] returning module_base_name: [module]
[  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
[  407.934245] returning module_base_name: [module]
[  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
[  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
[  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
[  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
[  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
[  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
[  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
[  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
[  407.934260] Call Trace:
[  407.934260]  <TASK>
[  407.934261]  ? init_module+0x5a/0xff9 [test_module]

note that it is able to decode RIP to an offset from module start or
init start now.

tested on linux->next (tag next-20211220)

Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
---
 kernel/module.c | 26 +++++++++++++++++++++++---
 1 file changed, 23 insertions(+), 3 deletions(-)

diff --git a/kernel/module.c b/kernel/module.c
index 320ec908045f..6e1621303156 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -4256,14 +4256,21 @@ static const char *find_kallsyms_symbol(struct module *mod,
 					unsigned long *offset)
 {
 	unsigned int i, best = 0;
-	unsigned long nextval, bestval;
+	unsigned long baseval, nextval, bestval;
 	struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
+	char *module_base_name;
 
 	/* At worse, next value is at end of module */
-	if (within_module_init(addr, mod))
+	if (within_module_init(addr, mod)) {
+		baseval = (unsigned long)mod->init_layout.base;
 		nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
-	else
+		module_base_name = "[module __init]";
+
+	} else {
+		baseval = (unsigned long)mod->core_layout.base;
 		nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
+		module_base_name = "[module]";
+	}
 
 	bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
 
@@ -4294,6 +4301,19 @@ static const char *find_kallsyms_symbol(struct module *mod,
 			nextval = thisval;
 	}
 
+	if ((is_module_text_address(addr) &&
+		(bestval < baseval || bestval > nextval))) {
+		/*
+		 * return MODULE base and offset if we could not find
+		 * any best match for text address
+		 */
+		if (size)
+			*size = nextval - baseval;
+		if (offset)
+			*offset = addr - baseval;
+		return module_base_name;
+	}
+
 	if (!best)
 		return NULL;
 
-- 
2.32.0


^ permalink raw reply related	[flat|nested] 36+ messages in thread

* Re: [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2021-12-22 13:23                   ` [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used Vimal Agrawal
@ 2021-12-23 10:36                     ` Christoph Hellwig
  2021-12-23 11:09                       ` Vimal Agrawal
  0 siblings, 1 reply; 36+ messages in thread
From: Christoph Hellwig @ 2021-12-23 10:36 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: mcgrof, vimal.Agrawal, masahiroy, michal.lkml, ndesaulniers,
	JBeulich, jeffm, sam, linux-kbuild, jeyu, linux-kernel

On Wed, Dec 22, 2021 at 06:53:32PM +0530, Vimal Agrawal wrote:
> If kernel modules are stripped off symbols (e.g. built by using strip
> --strip-unneeded option) then stack traces in dmesg do not show symbol

We never build modules with that ёption, so this is completely pointless.

NAK.

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2021-12-23 10:36                     ` Christoph Hellwig
@ 2021-12-23 11:09                       ` Vimal Agrawal
  2021-12-24  6:47                         ` Christoph Hellwig
  0 siblings, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2021-12-23 11:09 UTC (permalink / raw)
  To: Christoph Hellwig
  Cc: Luis Chamberlain, Vimal Agrawal, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel

Hi Christoph,

On Thu, Dec 23, 2021 at 4:06 PM Christoph Hellwig <hch@infradead.org> wrote:
>
> We never build modules with that ёption, so this is completely pointless.
>
we use openwrt for build and packaging and it has been using this
option for long.

kbuild documentation says the following for INSTALL_MOD_STRIP:
If this variable is specified, it will cause modules to be stripped
after they are installed. If INSTALL_MOD_STRIP is ‘1’, then the
default option –strip-debug will be used. Otherwise, the
INSTALL_MOD_STRIP value will be used as the option(s) to the strip
command.

So if kbuild does not support INSTALL_MOD_STRIP=--strip-unneeded
option then we should call out what it supports and should not even
allow what is not supported. We don't know what other options others
may be using but if we allow it then we should support it and it
should not behave erratic just because someone is using a
non-recommended option.

Vimal

> NAK.

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2021-12-23 11:09                       ` Vimal Agrawal
@ 2021-12-24  6:47                         ` Christoph Hellwig
  2021-12-25  1:08                           ` Vimal Agrawal
  0 siblings, 1 reply; 36+ messages in thread
From: Christoph Hellwig @ 2021-12-24  6:47 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: Christoph Hellwig, Luis Chamberlain, Vimal Agrawal,
	Masahiro Yamada, Michal Marek, Nick Desaulniers, Jan Beulich,
	Jeff Mahoney, Sam Ravnborg, linux-kbuild, jeyu, linux-kernel

On Thu, Dec 23, 2021 at 04:39:15PM +0530, Vimal Agrawal wrote:
> Hi Christoph,
> 
> On Thu, Dec 23, 2021 at 4:06 PM Christoph Hellwig <hch@infradead.org> wrote:
> >
> > We never build modules with that ёption, so this is completely pointless.
> >
> we use openwrt for build and packaging and it has been using this
> option for long.
> 
> kbuild documentation says the following for INSTALL_MOD_STRIP:
> If this variable is specified, it will cause modules to be stripped
> after they are installed. If INSTALL_MOD_STRIP is ‘1’, then the
> default option –strip-debug will be used. Otherwise, the
> INSTALL_MOD_STRIP value will be used as the option(s) to the strip
> command.
> 
> So if kbuild does not support INSTALL_MOD_STRIP=--strip-unneeded
> option then we should call out what it supports and should not even
> allow what is not supported. We don't know what other options others
> may be using but if we allow it then we should support it and it
> should not behave erratic just because someone is using a
> non-recommended option.

I don't think we can support passing arbitrary linker options and
expects things to work.  If we want to support --strip-unneeded
it needs a good rationale and be added as a direct config option.

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2021-12-24  6:47                         ` Christoph Hellwig
@ 2021-12-25  1:08                           ` Vimal Agrawal
  2022-01-11 15:49                             ` Luis Chamberlain
  0 siblings, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2021-12-25  1:08 UTC (permalink / raw)
  To: Christoph Hellwig
  Cc: Luis Chamberlain, Vimal Agrawal, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel

On Fri, Dec 24, 2021 at 12:17 PM Christoph Hellwig <hch@infradead.org> wrote:
>
> I don't think we can support passing arbitrary linker options and
> expects things to work.  If we want to support --strip-unneeded
> it needs a good rationale and be added as a direct config option.
INSTALL_MOD_STRIP was provided to give flexibility for providing
strippping options. It will be a separate discussion if we want to
continue allowing this flexibility or not but it is available now. I
see that it works but just that it is behaving erratically during
symbol decodes. I tried few other stripping options. --strip-all does
not work and insmod fails as it needs some symbols which is fine as it
is hinting the user there is a problem with stripping option. This is
not the case with --strip-unneeded option as it builds and loads/works
fine but fails to decode symbols properly sometimes.

One of the rationale for --strip-unneeded option is that it
significantly reduces the size of .ko without affecting its
functionality ( though debuggability takes a hit). I guess many
platforms/products that need limited memory footprint might be using
this option.

I am fine if we decide to say that --strip-unneeded option is not
supported by kbuild/INSTALL_MOD_STRIP which is not the case now. In
that case, I agree that this patch will not even be required.

Vimal

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2021-12-25  1:08                           ` Vimal Agrawal
@ 2022-01-11 15:49                             ` Luis Chamberlain
  2022-01-12  8:36                               ` Vimal Agrawal
  0 siblings, 1 reply; 36+ messages in thread
From: Luis Chamberlain @ 2022-01-11 15:49 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: Christoph Hellwig, Vimal Agrawal, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel

On Sat, Dec 25, 2021 at 06:38:02AM +0530, Vimal Agrawal wrote:
> On Fri, Dec 24, 2021 at 12:17 PM Christoph Hellwig <hch@infradead.org> wrote:
> >
> > I don't think we can support passing arbitrary linker options and
> > expects things to work.  If we want to support --strip-unneeded
> > it needs a good rationale and be added as a direct config option.
> INSTALL_MOD_STRIP was provided to give flexibility for providing
> strippping options.

Yes but the point here is the heuristic you are adding for
when "--strip-unneeded" is used is now *always* being used and
we have no way of knowing this. So I'd agree with Christoph that
if we want to support this it might make sense to make a kconfig
option for enabling "--strip-unneeded" and then another for this
heuristic.

You may want to work on top of Aaron's patches as that would make
adding new kconfig entries for modules much cleaner:

https://lkml.kernel.org/r/20220106234319.2067842-1-atomlin@redhat.com

I hope to review those this week, so I might have a tree you can
work off on by the end of this or next week.

  Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2022-01-11 15:49                             ` Luis Chamberlain
@ 2022-01-12  8:36                               ` Vimal Agrawal
  2022-01-13 15:23                                 ` Luis Chamberlain
  0 siblings, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2022-01-12  8:36 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Christoph Hellwig, Vimal Agrawal, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel

On Tue, Jan 11, 2022 at 9:19 PM Luis Chamberlain <mcgrof@kernel.org> wrote:
> Yes but the point here is the heuristic you are adding for
> when "--strip-unneeded" is used is now *always* being used and
> we have no way of knowing this. So I'd agree with Christoph that
> if we want to support this it might make sense to make a kconfig
> option for enabling "--strip-unneeded" and then another for this
> heuristic.

This heuristic is applicable to any case when an address inside a
module can not be decoded to any known symbol. e.g. anyone can still
build with ----strip-all though module load fails with this option.
but one can add or remove symbols manually or use objcopy or some
other utility to play with symbols. It does not matter for
functionality much if symbols are available or not and it is just that
symbol decodes in traces are not providing help as it displays
absolute address in such cases.

There are several options in strip command and we can't have kconfig
for each such option. All options are supported currently unless the
module is so broken that it can even be loaded ( e.g. --strip-all
option).

Vimal

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2022-01-12  8:36                               ` Vimal Agrawal
@ 2022-01-13 15:23                                 ` Luis Chamberlain
  2022-01-17  6:54                                   ` [PATCH v3] kernel/module.c: heuristic enhancement in case symbols are missing e.g. " Vimal Agrawal
  2022-01-17  7:34                                   ` [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used Vimal Agrawal
  0 siblings, 2 replies; 36+ messages in thread
From: Luis Chamberlain @ 2022-01-13 15:23 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: Christoph Hellwig, Vimal Agrawal, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel

On Wed, Jan 12, 2022 at 02:06:48PM +0530, Vimal Agrawal wrote:
> On Tue, Jan 11, 2022 at 9:19 PM Luis Chamberlain <mcgrof@kernel.org> wrote:
> > Yes but the point here is the heuristic you are adding for
> > when "--strip-unneeded" is used is now *always* being used and
> > we have no way of knowing this. So I'd agree with Christoph that
> > if we want to support this it might make sense to make a kconfig
> > option for enabling "--strip-unneeded" and then another for this
> > heuristic.
> 
> This heuristic is applicable to any case when an address inside a
> module can not be decoded to any known symbol. e.g. 

You mean it is safe for that case too? If so can you add this to the
commit log as well?

> anyone can still
> build with ----strip-all though module load fails with this option.
> but one can add or remove symbols manually or use objcopy or some
> other utility to play with symbols. It does not matter for
> functionality much if symbols are available or not and it is just that
> symbol decodes in traces are not providing help as it displays
> absolute address in such cases.
> 
> There are several options in strip command and we can't have kconfig
> for each such option. 

This is a good point. Pointing out it is safe regardless of the
situation in the commit log I think does this heuristic more justice.

Can you resend with that being clarified? I'll still have to test this.
Can you also use the modules-next tree? I'll still have to test this.

[0] https://git.kernel.org/pub/scm/linux/kernel/git/mcgrof/linux.git/ branch modules-next

  Luis

> All options are supported currently unless the
> module is so broken that it can even be loaded ( e.g. --strip-all
> option).
> 
> Vimal

^ permalink raw reply	[flat|nested] 36+ messages in thread

* [PATCH v3] kernel/module.c: heuristic enhancement in case symbols are missing e.g. when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2022-01-13 15:23                                 ` Luis Chamberlain
@ 2022-01-17  6:54                                   ` Vimal Agrawal
  2022-02-02 20:20                                     ` Luis Chamberlain
  2022-01-17  7:34                                   ` [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used Vimal Agrawal
  1 sibling, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2022-01-17  6:54 UTC (permalink / raw)
  To: mcgrof
  Cc: vimal.Agrawal, hch, masahiroy, michal.lkml, ndesaulniers,
	JBeulich, jeffm, sam, linux-kbuild, jeyu, linux-kernel, avimalin,
	Vimal Agrawal

If kernel modules are stripped off symbols for some reason (e.g. built by
using strip --strip-unneeded option) then stack traces in dmesg do not show
symbol name for address. It just prints absolute address sometimes (if
there is no good match with any symbol)
e.g.

[245864.699580]  do_nmi+0x12f/0x370
[245864.699583]  end_repeat_nmi+0x16/0x50
[245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
[245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
[245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
[245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
[245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
[245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
[245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
[245864.699590]  ? 0xffffffffc06b61a0
[245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
[245864.699593]  ? 0xffffffffc06b67ec
[245864.699594]  </NMI>

Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
stack trace as absolute address.
There is no easy way in case box crashes as we loose information on load
address of specific module. This changes the symbol decoding (in kernel/
module.c) such that it can print offset from start of section (.text or
.init.text) in case there is no good match with any symbol.

It will now decode address in such cases to [module]+ offset/size or
[module __init]+offset/size depending on where the address lies (in
core/.text or init/.init.text section of module).

One can use objdump/readelf/nm to find symbols with offset from
.init.text and .text sections.

steps to reproduce the problem:
-------------------------------
1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
2. Build and strip the module using --strip-unneeded option
3. Load the module and check RIP in dmesg

tests done:
-----------
1. Added WARN_ON_ONE(1) in functions of a module for testing
-------------------------------------------------------------
[  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
[  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
[  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
[  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
[  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
[  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
[  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
[  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
[  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
[  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
[  407.934113] Call Trace:
[  407.934114]  <TASK>
[  407.934116]  ? init_module+0x55/0xff9 [test_module]
...
[  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
[  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
[  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
[  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
[  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
[  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
[  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
[  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
[  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
[  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
[  407.934260] Call Trace:
[  407.934260]  <TASK>
[  407.934261]  ? init_module+0x5a/0xff9 [test_module]

note that it is able to decode RIP to an offset from module start or
init start now.

tested on linux->next (tag next-20211220)

Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
---
 kernel/module.c | 26 +++++++++++++++++++++++---
 1 file changed, 23 insertions(+), 3 deletions(-)

diff --git a/kernel/module.c b/kernel/module.c
index 24dab046e16c..4de15c06e760 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -4270,14 +4270,21 @@ static const char *find_kallsyms_symbol(struct module *mod,
 					unsigned long *offset)
 {
 	unsigned int i, best = 0;
-	unsigned long nextval, bestval;
+	unsigned long baseval, nextval, bestval;
 	struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
+	char *module_base_name;
 
 	/* At worse, next value is at end of module */
-	if (within_module_init(addr, mod))
+	if (within_module_init(addr, mod)) {
+		baseval = (unsigned long)mod->init_layout.base;
 		nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
-	else
+		module_base_name = "[module __init]";
+
+	} else {
+		baseval = (unsigned long)mod->core_layout.base;
 		nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
+		module_base_name = "[module]";
+	}
 
 	bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
 
@@ -4308,6 +4315,19 @@ static const char *find_kallsyms_symbol(struct module *mod,
 			nextval = thisval;
 	}
 
+	if ((is_module_text_address(addr) &&
+		(bestval < baseval || bestval > nextval))) {
+		/*
+		 * return MODULE base and offset if we could not find
+		 * any best match for text address
+		 */
+		if (size)
+			*size = nextval - baseval;
+		if (offset)
+			*offset = addr - baseval;
+		return module_base_name;
+	}
+
 	if (!best)
 		return NULL;
 
-- 
2.32.0


^ permalink raw reply related	[flat|nested] 36+ messages in thread

* Re: [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2022-01-13 15:23                                 ` Luis Chamberlain
  2022-01-17  6:54                                   ` [PATCH v3] kernel/module.c: heuristic enhancement in case symbols are missing e.g. " Vimal Agrawal
@ 2022-01-17  7:34                                   ` Vimal Agrawal
  1 sibling, 0 replies; 36+ messages in thread
From: Vimal Agrawal @ 2022-01-17  7:34 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Christoph Hellwig, Vimal Agrawal, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel

Hi Luis,

On Thu, Jan 13, 2022 at 8:53 PM Luis Chamberlain <mcgrof@kernel.org> wrote:

>
> You mean it is safe for that case too? If so can you add this to the
> commit log as well?
>
yes. updated in the commit log.

> Can you also use the modules-next tree? I'll still have to test this.
>
> [0] https://git.kernel.org/pub/scm/linux/kernel/git/mcgrof/linux.git/ branch modules-next
>
I am not sure of modules-next but I created the patch (v3) on latest
linux-next (next-20220116). Hope it suffices. Sent patch v3 already.

Vimal

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v3] kernel/module.c: heuristic enhancement in case symbols are missing e.g. when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2022-01-17  6:54                                   ` [PATCH v3] kernel/module.c: heuristic enhancement in case symbols are missing e.g. " Vimal Agrawal
@ 2022-02-02 20:20                                     ` Luis Chamberlain
  2022-02-03  5:54                                       ` Vimal Agrawal
  2022-02-03  6:06                                       ` [PATCH v4] modules: add heuristic when stripping unneeded symbols Vimal Agrawal
  0 siblings, 2 replies; 36+ messages in thread
From: Luis Chamberlain @ 2022-02-02 20:20 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: vimal.Agrawal, hch, masahiroy, michal.lkml, ndesaulniers,
	JBeulich, jeffm, sam, linux-kbuild, jeyu, linux-kernel

The subject should only be about 70-75 characters. You're going
way overboard here..

Try:

modules: add heuristic when stripping unneeded symbols

Then please describe in your commit log that on OpenWrt the
INSTALL_MOD_STRIP="--strip-unneeded" at kernel/module install
time, and so modules are stripped of unneeded symbols.

Your commit log currently does not give us the idea that this
is in fact a useful feature to consider, mentioning that this
is in fact used in OpenWrt tries to help us get a better idea
of a possible user of it and a potential benefit.

On Mon, Jan 17, 2022 at 12:24:52PM +0530, Vimal Agrawal wrote:
> If kernel modules are stripped off symbols for some reason (e.g. built by
> using strip --strip-unneeded option) then stack traces in dmesg do not show
> symbol name for address. It just prints absolute address sometimes (if
> there is no good match with any symbol)
> e.g.
> 
> [245864.699580]  do_nmi+0x12f/0x370
> [245864.699583]  end_repeat_nmi+0x16/0x50
> [245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
> [245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
> [245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
> [245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
> [245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
> [245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
> [245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
> [245864.699590]  ? 0xffffffffc06b61a0
> [245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
> [245864.699593]  ? 0xffffffffc06b67ec
> [245864.699594]  </NMI>
> 
> Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
> stack trace as absolute address.
> There is no easy way in case box crashes as we loose information on load
> address of specific module. This changes the symbol decoding (in kernel/
> module.c) such that it can print offset from start of section (.text or
> .init.text) in case there is no good match with any symbol.
> 
> It will now decode address in such cases to [module]+ offset/size or
> [module __init]+offset/size depending on where the address lies (in
> core/.text or init/.init.text section of module).
> 
> One can use objdump/readelf/nm to find symbols with offset from
> .init.text and .text sections.
> 
> steps to reproduce the problem:
> -------------------------------
> 1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
> 2. Build and strip the module using --strip-unneeded option
> 3. Load the module and check RIP in dmesg
> 
> tests done:
> -----------
> 1. Added WARN_ON_ONE(1) in functions of a module for testing
> -------------------------------------------------------------
> [  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> [  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
> [  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
> [  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> [  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> [  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> [  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> [  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> [  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> [  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> [  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
> [  407.934113] Call Trace:
> [  407.934114]  <TASK>
> [  407.934116]  ? init_module+0x55/0xff9 [test_module]
> ...
> [  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> [  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
> [  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
> [  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> [  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> [  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> [  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> [  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> [  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> [  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> [  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
> [  407.934260] Call Trace:
> [  407.934260]  <TASK>
> [  407.934261]  ? init_module+0x5a/0xff9 [test_module]
> 
> note that it is able to decode RIP to an offset from module start or
> init start now.
> 
> tested on linux->next (tag next-20211220)

Sorry but for some reason this is not working on my end, but then
again I'm not able to get the stripped out results you see either.
So it could be I just have too many debugging options enabled
that makes INSTALL_MOD_STRIP="--strip-unneeded" not really do
much. I don't know if that is possible but I will have to try
to reduce my build options to test.

> Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
> ---
>  kernel/module.c | 26 +++++++++++++++++++++++---
>  1 file changed, 23 insertions(+), 3 deletions(-)
> 
> diff --git a/kernel/module.c b/kernel/module.c
> index 24dab046e16c..4de15c06e760 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -4270,14 +4270,21 @@ static const char *find_kallsyms_symbol(struct module *mod,
>  					unsigned long *offset)
>  {
>  	unsigned int i, best = 0;
> -	unsigned long nextval, bestval;
> +	unsigned long baseval, nextval, bestval;
>  	struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
> +	char *module_base_name;
>  
>  	/* At worse, next value is at end of module */
> -	if (within_module_init(addr, mod))
> +	if (within_module_init(addr, mod)) {
> +		baseval = (unsigned long)mod->init_layout.base;
>  		nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
> -	else
> +		module_base_name = "[module __init]";
> +
> +	} else {
> +		baseval = (unsigned long)mod->core_layout.base;
>  		nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
> +		module_base_name = "[module]";
> +	}
>  
>  	bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
>  
> @@ -4308,6 +4315,19 @@ static const char *find_kallsyms_symbol(struct module *mod,
>  			nextval = thisval;
>  	}
>  
> +	if ((is_module_text_address(addr) &&
> +		(bestval < baseval || bestval > nextval))) {
> +		/*
> +		 * return MODULE base and offset if we could not find
> +		 * any best match for text address
> +		 */
> +		if (size)
> +			*size = nextval - baseval;
> +		if (offset)
> +			*offset = addr - baseval;
> +		return module_base_name;
> +	}
> +

I don't like this code to go before the check for !best. You did not
have this in your v1 or v2 patch. Why did you change it?

  Luis

>  	if (!best)
>  		return NULL;
>  
> -- 
> 2.32.0
> 

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v3] kernel/module.c: heuristic enhancement in case symbols are missing e.g. when INSTALL_MOD_STRIP= "--strip-unneeded" is used
  2022-02-02 20:20                                     ` Luis Chamberlain
@ 2022-02-03  5:54                                       ` Vimal Agrawal
  2022-02-03  6:06                                       ` [PATCH v4] modules: add heuristic when stripping unneeded symbols Vimal Agrawal
  1 sibling, 0 replies; 36+ messages in thread
From: Vimal Agrawal @ 2022-02-03  5:54 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Vimal Agrawal, Christoph Hellwig, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel, gregkh

Hi Luis,

> Try:
>
> modules: add heuristic when stripping unneeded symbols
>
> Then please describe in your commit log that on OpenWrt the
> INSTALL_MOD_STRIP="--strip-unneeded" at kernel/module install
> time, and so modules are stripped of unneeded symbols.
Yes, Thanks, I will send the updated patch shortly.

> Sorry but for some reason this is not working on my end, but then
> again I'm not able to get the stripped out results you see either.
> So it could be I just have too many debugging options enabled
> that makes INSTALL_MOD_STRIP="--strip-unneeded" not really do
> much. I don't know if that is possible but I will have to try
> to reduce my build options to test.

Yes, there could be some dependencies due to other debug options and
it may not be able to strip it to a good extent.

Are you trying with changes in test_module.c?
I was able to reproduce it easily on ubuntu 21.10 with following patch:

diff --git a/lib/test_module.c b/lib/test_module.c
index debd19e35198..53578e7a34d7 100644
--- a/lib/test_module.c
+++ b/lib/test_module.c
@@ -14,10 +14,25 @@
 #include <linux/module.h>
 #include <linux/printk.h>

+static void test_module_warn_start(int x)
+{
+        if (x) WARN_ON_ONCE(1);
+}
+
+static void __init test_module_warn_init(int x)
+{
+        if (x) WARN_ON_ONCE(1);
+}
+
+
 static int __init test_module_init(void)
 {
  pr_warn("Hello, world\n");
+        printk("address of test_module_warn_int is %px\n",
test_module_warn_init);
+        printk("address of test_module_warn_start is %px\n",
test_module_warn_start);

+ test_module_warn_init(1);
+ test_module_warn_start(1);
  return 0;
 }

After building this module, I used the following command to strip it:
> strip --strip-unneeded test_module.ko
and then loaded the stripped .ko using insmod.

Vimal

^ permalink raw reply related	[flat|nested] 36+ messages in thread

* [PATCH v4] modules: add heuristic when stripping unneeded symbols
  2022-02-02 20:20                                     ` Luis Chamberlain
  2022-02-03  5:54                                       ` Vimal Agrawal
@ 2022-02-03  6:06                                       ` Vimal Agrawal
  2022-02-04  8:39                                         ` [PATCH v5] " Vimal Agrawal
  1 sibling, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2022-02-03  6:06 UTC (permalink / raw)
  To: mcgrof
  Cc: linux-kernel, gregkh, hch, masahiroy, michal.lkml, ndesaulniers,
	JBeulich, jeffm, sam, linux-kbuild, jeyu, avimalin,
	vimal.agrawal

If kernel modules are stripped off symbols for some reason then stack
traces in dmesg do not show symbol name for address. It just prints
absolute address sometimes (if there is no good match with any symbol)

This was seen with OpenWrt which uses option INSTALL_MOD_STRIP=
"--strip-unneeded" at kernel/module build/install time, and so modules
are stripped off unneeded symbols.

[245864.699580]  do_nmi+0x12f/0x370
[245864.699583]  end_repeat_nmi+0x16/0x50
[245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
[245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
[245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
[245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
[245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
[245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
[245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
[245864.699590]  ? 0xffffffffc06b61a0
[245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
[245864.699593]  ? 0xffffffffc06b67ec
[245864.699594]  </NMI>

Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
stack trace as absolute address. There is no easy way in case box crashes
as we loose information on load address of specific module.

This changes the symbol decoding (in kernel/module.c) such that it can
print offset from start of section (.text or .init.text) in case there
is no good match with any symbol.

It will now decode address in such cases to [module]+ offset/size or
[module __init]+offset/size depending on where the address lies (in
core/.text or init/.init.text section of module).

One can use objdump/readelf/nm to find symbols with offset from .init.text
and .text sections.

steps to reproduce the problem:
-------------------------------
1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
2. Build and strip the module using --strip-unneeded option
3. Load the module and check RIP in dmesg

tests done:
-----------
1. Added WARN_ON_ONE(1) in functions of a module for testing
-------------------------------------------------------------
[  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
[  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
[  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
[  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
[  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
[  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
[  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
[  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
[  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
[  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
[  407.934113] Call Trace:
[  407.934114]  <TASK>
[  407.934116]  ? init_module+0x55/0xff9 [test_module]
...
[  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
[  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
[  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
[  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
[  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
[  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
[  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
[  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
[  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
[  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
[  407.934260] Call Trace:
[  407.934260]  <TASK>
[  407.934261]  ? init_module+0x5a/0xff9 [test_module]

note that it is able to decode RIP to an offset from module start or
init start now.

tested on linux->next (tag next-20211220)

Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
---
 kernel/module.c | 26 +++++++++++++++++++++++---
 1 file changed, 23 insertions(+), 3 deletions(-)

diff --git a/kernel/module.c b/kernel/module.c
index 24dab046e16c..4de15c06e760 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -4270,14 +4270,21 @@ static const char *find_kallsyms_symbol(struct module *mod,
 					unsigned long *offset)
 {
 	unsigned int i, best = 0;
-	unsigned long nextval, bestval;
+	unsigned long baseval, nextval, bestval;
 	struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
+	char *module_base_name;
 
 	/* At worse, next value is at end of module */
-	if (within_module_init(addr, mod))
+	if (within_module_init(addr, mod)) {
+		baseval = (unsigned long)mod->init_layout.base;
 		nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
-	else
+		module_base_name = "[module __init]";
+
+	} else {
+		baseval = (unsigned long)mod->core_layout.base;
 		nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
+		module_base_name = "[module]";
+	}
 
 	bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
 
@@ -4308,6 +4315,19 @@ static const char *find_kallsyms_symbol(struct module *mod,
 			nextval = thisval;
 	}
 
+	if ((is_module_text_address(addr) &&
+		(bestval < baseval || bestval > nextval))) {
+		/*
+		 * return MODULE base and offset if we could not find
+		 * any best match for text address
+		 */
+		if (size)
+			*size = nextval - baseval;
+		if (offset)
+			*offset = addr - baseval;
+		return module_base_name;
+	}
+
 	if (!best)
 		return NULL;
 
-- 
2.32.0


^ permalink raw reply related	[flat|nested] 36+ messages in thread

* [PATCH v5] modules: add heuristic when stripping unneeded symbols
  2022-02-03  6:06                                       ` [PATCH v4] modules: add heuristic when stripping unneeded symbols Vimal Agrawal
@ 2022-02-04  8:39                                         ` Vimal Agrawal
  2022-02-04 21:47                                           ` Luis Chamberlain
  0 siblings, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2022-02-04  8:39 UTC (permalink / raw)
  To: mcgrof
  Cc: hch, masahiroy, michal.lkml, ndesaulniers, JBeulich, jeffm, sam,
	linux-kbuild, jeyu, linux-kernel, avimalin, nishit.shah,
	Vimal Agrawal, Dirk VanDerMerwe

If kernel modules are stripped off symbols for some reason then stack
traces in dmesg do not show symbol name for address. It just prints
absolute address sometimes (if there is no good match with any symbol)

This was seen with OpenWrt which uses option INSTALL_MOD_STRIP=
"--strip-unneeded" at kernel/module build/install time, and so modules
are stripped off unneeded symbols.

[245864.699580]  do_nmi+0x12f/0x370
[245864.699583]  end_repeat_nmi+0x16/0x50
[245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
[245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
[245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
[245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
[245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
[245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
[245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
[245864.699590]  ? 0xffffffffc06b61a0
[245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
[245864.699593]  ? 0xffffffffc06b67ec
[245864.699594]  </NMI>

Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
stack trace as absolute address. There is no easy way in case box crashes
as we loose information on load address of specific module.

This changes the symbol decoding (in kernel/module.c) such that it can
print offset from start of section (.text or .init.text) in case there
is no good match with any symbol.

It will now decode address in such cases to [module]+ offset/size or
[module __init]+offset/size depending on where the address lies (in
core/.text or init/.init.text section of module).

One can use objdump/readelf/nm to find symbols with offset from .init.text
and .text sections.

steps to reproduce the problem:
-------------------------------
1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
2. Build and strip the module using --strip-unneeded option
3. Load the module and check RIP in dmesg

tests done:
-----------
1. Added WARN_ON_ONE(1) in functions of a module for testing
-------------------------------------------------------------
[  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
[  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
[  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
[  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
[  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
[  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
[  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
[  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
[  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
[  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
[  407.934113] Call Trace:
[  407.934114]  <TASK>
[  407.934116]  ? init_module+0x55/0xff9 [test_module]
...
[  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
[  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
[  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
[  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
[  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
[  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
[  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
[  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
[  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
[  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
[  407.934260] Call Trace:
[  407.934260]  <TASK>
[  407.934261]  ? init_module+0x5a/0xff9 [test_module]

note that it is able to decode RIP to an offset from module start or
init start now.

tested on linux->next (tag next-20211220)

Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
Acked-by: Nishit Shah <nishit.shah@sophos.com>
Suggested-by: Dirk VanDerMerwe <Dirk.VanDerMerwe@Sophos.com>
---
 kernel/module.c | 26 +++++++++++++++++++++++---
 1 file changed, 23 insertions(+), 3 deletions(-)

diff --git a/kernel/module.c b/kernel/module.c
index 24dab046e16c..4de15c06e760 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -4270,14 +4270,21 @@ static const char *find_kallsyms_symbol(struct module *mod,
 					unsigned long *offset)
 {
 	unsigned int i, best = 0;
-	unsigned long nextval, bestval;
+	unsigned long baseval, nextval, bestval;
 	struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
+	char *module_base_name;
 
 	/* At worse, next value is at end of module */
-	if (within_module_init(addr, mod))
+	if (within_module_init(addr, mod)) {
+		baseval = (unsigned long)mod->init_layout.base;
 		nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
-	else
+		module_base_name = "[module __init]";
+
+	} else {
+		baseval = (unsigned long)mod->core_layout.base;
 		nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
+		module_base_name = "[module]";
+	}
 
 	bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
 
@@ -4308,6 +4315,19 @@ static const char *find_kallsyms_symbol(struct module *mod,
 			nextval = thisval;
 	}
 
+	if ((is_module_text_address(addr) &&
+		(bestval < baseval || bestval > nextval))) {
+		/*
+		 * return MODULE base and offset if we could not find
+		 * any best match for text address
+		 */
+		if (size)
+			*size = nextval - baseval;
+		if (offset)
+			*offset = addr - baseval;
+		return module_base_name;
+	}
+
 	if (!best)
 		return NULL;
 
-- 
2.32.0


^ permalink raw reply related	[flat|nested] 36+ messages in thread

* Re: [PATCH v5] modules: add heuristic when stripping unneeded symbols
  2022-02-04  8:39                                         ` [PATCH v5] " Vimal Agrawal
@ 2022-02-04 21:47                                           ` Luis Chamberlain
  2022-02-07 13:21                                             ` Vimal Agrawal
  0 siblings, 1 reply; 36+ messages in thread
From: Luis Chamberlain @ 2022-02-04 21:47 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: hch, masahiroy, michal.lkml, ndesaulniers, JBeulich, jeffm, sam,
	linux-kbuild, jeyu, linux-kernel, nishit.shah, Vimal Agrawal,
	Dirk VanDerMerwe

On Fri, Feb 04, 2022 at 02:09:32PM +0530, Vimal Agrawal wrote:
> If kernel modules are stripped off symbols for some reason then stack
> traces in dmesg do not show symbol name for address. It just prints
> absolute address sometimes (if there is no good match with any symbol)
> 
> This was seen with OpenWrt which uses option INSTALL_MOD_STRIP=
> "--strip-unneeded" at kernel/module build/install time, and so modules
> are stripped off unneeded symbols.
> 
> [245864.699580]  do_nmi+0x12f/0x370
> [245864.699583]  end_repeat_nmi+0x16/0x50
> [245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
> [245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
> [245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
> [245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
> [245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
> [245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
> [245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
> [245864.699590]  ? 0xffffffffc06b61a0
> [245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
> [245864.699593]  ? 0xffffffffc06b67ec
> [245864.699594]  </NMI>
> 
> Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
> stack trace as absolute address. There is no easy way in case box crashes
> as we loose information on load address of specific module.
> 
> This changes the symbol decoding (in kernel/module.c) such that it can
> print offset from start of section (.text or .init.text) in case there
> is no good match with any symbol.
> 
> It will now decode address in such cases to [module]+ offset/size or
> [module __init]+offset/size depending on where the address lies (in
> core/.text or init/.init.text section of module).
> 
> One can use objdump/readelf/nm to find symbols with offset from .init.text
> and .text sections.
> 
> steps to reproduce the problem:
> -------------------------------
> 1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
> 2. Build and strip the module using --strip-unneeded option
> 3. Load the module and check RIP in dmesg
> 
> tests done:
> -----------
> 1. Added WARN_ON_ONE(1) in functions of a module for testing
> -------------------------------------------------------------
> [  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> [  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
> [  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
> [  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> [  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> [  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> [  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> [  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> [  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> [  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> [  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
> [  407.934113] Call Trace:
> [  407.934114]  <TASK>
> [  407.934116]  ? init_module+0x55/0xff9 [test_module]
> ...
> [  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> [  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
> [  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
> [  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> [  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> [  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> [  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> [  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> [  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> [  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> [  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
> [  407.934260] Call Trace:
> [  407.934260]  <TASK>
> [  407.934261]  ? init_module+0x5a/0xff9 [test_module]
> 
> note that it is able to decode RIP to an offset from module start or
> init start now.
> 
> tested on linux->next (tag next-20211220)
> 
> Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
> Acked-by: Nishit Shah <nishit.shah@sophos.com>
> Suggested-by: Dirk VanDerMerwe <Dirk.VanDerMerwe@Sophos.com>
> ---
>  kernel/module.c | 26 +++++++++++++++++++++++---
>  1 file changed, 23 insertions(+), 3 deletions(-)
> 
> diff --git a/kernel/module.c b/kernel/module.c
> index 24dab046e16c..4de15c06e760 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -4270,14 +4270,21 @@ static const char *find_kallsyms_symbol(struct module *mod,
>  					unsigned long *offset)
>  {
>  	unsigned int i, best = 0;
> -	unsigned long nextval, bestval;
> +	unsigned long baseval, nextval, bestval;
>  	struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
> +	char *module_base_name;
>  
>  	/* At worse, next value is at end of module */
> -	if (within_module_init(addr, mod))
> +	if (within_module_init(addr, mod)) {
> +		baseval = (unsigned long)mod->init_layout.base;
>  		nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
> -	else
> +		module_base_name = "[module __init]";
> +
> +	} else {
> +		baseval = (unsigned long)mod->core_layout.base;
>  		nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
> +		module_base_name = "[module]";
> +	}
>  
>  	bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
>  
> @@ -4308,6 +4315,19 @@ static const char *find_kallsyms_symbol(struct module *mod,
>  			nextval = thisval;
>  	}
>  
> +	if ((is_module_text_address(addr) &&
> +		(bestval < baseval || bestval > nextval))) {
> +		/*
> +		 * return MODULE base and offset if we could not find
> +		 * any best match for text address
> +		 */
> +		if (size)
> +			*size = nextval - baseval;
> +		if (offset)
> +			*offset = addr - baseval;
> +		return module_base_name;
> +	}
> +

You did not explain why you change your code to not use the below
(!best) branch. I'd much prefer it there as that is when we know
for sure we have no real symbol defined.

  Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v5] modules: add heuristic when stripping unneeded symbols
  2022-02-04 21:47                                           ` Luis Chamberlain
@ 2022-02-07 13:21                                             ` Vimal Agrawal
  2022-02-07 22:07                                               ` Luis Chamberlain
  0 siblings, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2022-02-07 13:21 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Christoph Hellwig, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel, nishit.shah, Vimal Agrawal,
	Dirk VanDerMerwe

>
> You did not explain why you change your code to not use the below
> (!best) branch. I'd much prefer it there as that is when we know
> for sure we have no real symbol defined.
>
>   Luis

Actually I had it  under (!best) in my first patch. I had to change it
because it was resolving the address to symbols like __this_module for
init address at times which is not correct for text address. It was
not entering inside if (!best) as it found some match but the match
was not correct. It could be fine for some non text addresses but not
for text addresses.

So I had to move this check out of (!best) and put a check explicitly
for text address to avoid any impact on non text addresses by
following:

+       if ((is_module_text_address(addr) &&
+               (bestval < baseval || bestval > nextval))) {
+               /*
+                * return MODULE base and offset if we could not find
+                * any best match for text address
+                */

I tested it on next-20220116-1-gff24014a52c0 today and I am able to
repro at least for init address easily with test_module.ko.
it is showing like following without the patch in my latest run (
decoding it to __this_module wrongly as mentioned earlier) :

[129558.843823] CPU: 2 PID: 39541 Comm: insmod Tainted: G        W   E
    5.16.0-next-20220116+ #6
[129558.843827] Hardware name: innotek GmbH VirtualBox/VirtualBox,
BIOS VirtualBox 12/01/2006
[129558.843829] RIP: 0010:__this_module+0x9fc4/0x9fc7 [test_module].
<<<<<<<<<<<======================
[129558.843840] Code: Unable to access opcode bytes at RIP 0xffffffffc083ffda.
[129558.843841] RSP: 0018:ffffa2cc800cbbf0 EFLAGS: 00010202
[129558.843844] RAX: 0000000000000035 RBX: 0000000000000000 RCX:
0000000000000000
[129558.843846] RDX: 0000000000000000 RSI: ffffffffb6d930f1 RDI:
0000000000000001
[129558.843848] RBP: ffffa2cc800cbbf8 R08: 0000000000000000 R09:
ffffa2cc800cb9f0
[129558.843849] R10: ffffa2cc800cb9e8 R11: ffffffffb7155108 R12:
ffffffffc0840007
[129558.843851] R13: ffff97acb458d580 R14: 0000000000000000 R15:
ffffffffc0836040
[129558.843853] FS:  00007f752eb90400(0000) GS:ffff97ad80f00000(0000)
knlGS:0000000000000000
[129558.843855] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[129558.843857] CR2: ffffffffc083ffda CR3: 0000000100786001 CR4:
00000000000706e0
[129558.843863] Call Trace:
[129558.843865]  <TASK>
[129558.843866]  ? init_module+0x40/0xff9 [test_module]

Not sure what has changed but it is not showing the absolute address
as I had seen earlier.

post my patch, it is showing like following:
[   59.600299] CPU: 1 PID: 1620 Comm: insmod Tainted: G            E
  5.16.0-next-20220116+ #7
[   59.600303] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS
VirtualBox 12/01/2006
[   59.600305] RIP: 0010:[module __init]+0x4/0x7 [test_module]
<<<<<<====================
[   59.600315] Code: Unable to access opcode bytes at RIP 0xffffffffc0827fda.
[   59.600316] RSP: 0018:ffffbda002a8fc20 EFLAGS: 00010202
[   59.600319] RAX: 0000000000000035 RBX: 0000000000000000 RCX: 0000000000000000
[   59.600321] RDX: 0000000000000000 RSI: ffffffffa0f930f1 RDI: 0000000000000001
[   59.600323] RBP: ffffbda002a8fc28 R08: 0000000000000000 R09: ffffbda002a8fa20
[   59.600325] R10: ffffbda002a8fa18 R11: ffffffffa1355108 R12: ffffffffc0828007
[   59.600326] R13: ffff9554c4e72220 R14: 0000000000000000 R15: ffffffffc0822040
[   59.600328] FS:  00007f9c773d8400(0000) GS:ffff9555c0e80000(0000)
knlGS:0000000000000000
[   59.600331] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   59.600333] CR2: ffffffffc0827fda CR3: 000000000c19c003 CR4: 00000000000706e0
[   59.600338] Call Trace:
[   59.600340]  <TASK>
[   59.600342]  ? init_module+0x40/0xff9 [test_module]

I can update the patch explaining this in comments in between the code.

Vimal

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v5] modules: add heuristic when stripping unneeded symbols
  2022-02-07 13:21                                             ` Vimal Agrawal
@ 2022-02-07 22:07                                               ` Luis Chamberlain
  2022-02-08  4:52                                                 ` Vimal Agrawal
  0 siblings, 1 reply; 36+ messages in thread
From: Luis Chamberlain @ 2022-02-07 22:07 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: Christoph Hellwig, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel, nishit.shah, Vimal Agrawal,
	Dirk VanDerMerwe

On Mon, Feb 07, 2022 at 06:51:50PM +0530, Vimal Agrawal wrote:
> >
> > You did not explain why you change your code to not use the below
> > (!best) branch. I'd much prefer it there as that is when we know
> > for sure we have no real symbol defined.
> >
> >   Luis
> 
> Actually I had it  under (!best) in my first patch. I had to change it
> because it was resolving the address to symbols like __this_module for
> init address at times which is not correct for text address.

Can you say that again?

> It was
> not entering inside if (!best) as it found some match but the match
> was not correct.

Is this a summary of what you said above and I could not understand?

OK so you're saying sometimes "best" is not true when we use
INSTALL_MOD_STRIP="--strip-unneeded"? This is news.

> It could be fine for some non text addresses but not
> for text addresses.

In particulr you seem to be suggesting that if --strip-unneeded was
used "best" could be incorrect for !is_module_text_address().

In any case, you completely changed things in your patch and did not
mention *any* of this in your follow up patch, leaving me to question
the validity of all this work.

> So I had to move this check out of (!best) and put a check explicitly
> for text address to avoid any impact on non text addresses by
> following:
> 
> +       if ((is_module_text_address(addr) &&
> +               (bestval < baseval || bestval > nextval))) {
> +               /*
> +                * return MODULE base and offset if we could not find
> +                * any best match for text address
> +                */
> 
> I tested it on next-20220116-1-gff24014a52c0 today and I am able to
> repro at least for init address easily with test_module.ko.

I tried to reproduce and couldn't and sent you a configuration to test.

> I can update the patch explaining this in comments in between the code.

The above is not clear and you need to make things crystal clear. If the
existing heuristic for best is not valid all the times it needs to be
made clear using a comment, sure.

If your heuristic is *better* than the existing heuristic *today*, that
needs to *also* be clearly spelled out. Your patch does none of this and
the commit log clearly does not reflect it.

  Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v5] modules: add heuristic when stripping unneeded symbols
  2022-02-07 22:07                                               ` Luis Chamberlain
@ 2022-02-08  4:52                                                 ` Vimal Agrawal
  2022-02-08 11:02                                                   ` [PATCH v6] " Vimal Agrawal
  2022-02-08 17:55                                                   ` [PATCH v5] " Luis Chamberlain
  0 siblings, 2 replies; 36+ messages in thread
From: Vimal Agrawal @ 2022-02-08  4:52 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Christoph Hellwig, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel, nishit.shah, Vimal Agrawal,
	Dirk VanDerMerwe, gregkh

> > Actually I had it  under (!best) in my first patch. I had to change it
> > because it was resolving the address to symbols like __this_module for
> > init address at times which is not correct for text address.
>
> Can you say that again?

I hit this a few times later after the first patch. Basically there
are all symbols in symbol table and best could be none zero ( means it
matched some symbol) but it may not be match to .text symbol for text
address ( esp. when --strip-unneeded is used as there are very few
symbols left after stripping)

> OK so you're saying sometimes "best" is not true when we use
> INSTALL_MOD_STRIP="--strip-unneeded"? This is news.
>
yes, best can be non zero and may not resolve to .text address when
--strip-unneeded is used. without stripping, it will definitely
resolve to some .text address closely matching in case of no stripping
but it can go wrong with stripping. I have seen it a few times post
the first patch during testing.

>
> In particulr you seem to be suggesting that if --strip-unneeded was
> used "best" could be incorrect for !is_module_text_address().
>
best could be incorrect even for text address when --strip-unneeded is used.
e.g. in my case, it is resolving .init.text address to __this_module

> In any case, you completely changed things in your patch and did not
> mention *any* of this in your follow up patch, leaving me to question
> the validity of all this work.
>
The Only change I did from the first patch was to move this hunk out of (!best).
Yes, I missed commenting it in the code.

> I tried to reproduce and couldn't and sent you a configuration to test.
>
Give me sometime and I will check with the config.
how does your nm test_module.ko look like after stripping?
it shows following for me:

vimal@ubuntu2:~/linux-next/linux/lib$ nm test_module.ko
0000000000000000 r .LC0
0000000000000000 D __this_module
                 U _printk
0000000000000000 T cleanup_module
0000000000000007 T init_module

> If your heuristic is *better* than the existing heuristic *today*, that
> needs to *also* be clearly spelled out. Your patch does none of this and
> the commit log clearly does not reflect it.
>
I wanted to avoid major change and fix only this particular back trace issue
else I would prefer a check in existing heuristic so that .text address always
resolves to .text symbol and .init to .init symbol and .data to .data symbol
always which is not the case currently that I found lately.

>   Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* [PATCH v6] modules: add heuristic when stripping unneeded symbols
  2022-02-08  4:52                                                 ` Vimal Agrawal
@ 2022-02-08 11:02                                                   ` Vimal Agrawal
  2022-02-08 11:13                                                     ` Vimal Agrawal
  2022-02-08 18:10                                                     ` Luis Chamberlain
  2022-02-08 17:55                                                   ` [PATCH v5] " Luis Chamberlain
  1 sibling, 2 replies; 36+ messages in thread
From: Vimal Agrawal @ 2022-02-08 11:02 UTC (permalink / raw)
  To: mcgrof
  Cc: hch, masahiroy, michal.lkml, ndesaulniers, JBeulich, jeffm, sam,
	linux-kbuild, jeyu, linux-kernel, avimalin, vimal.agrawal,
	nishit.shah, gregkh, Dirk VanDerMerwe

If kernel modules are stripped off symbols for some reason then stack
traces in dmesg do not show symbol name for address. It just prints
absolute address sometimes (if there is no good match with any symbol)

This was seen with OpenWrt which uses option INSTALL_MOD_STRIP=
"--strip-unneeded" at kernel/module build/install time, and so modules
are stripped off unneeded symbols.

[245864.699580]  do_nmi+0x12f/0x370
[245864.699583]  end_repeat_nmi+0x16/0x50
[245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
[245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
[245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
[245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
[245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
[245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
[245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
[245864.699590]  ? 0xffffffffc06b61a0
[245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
[245864.699593]  ? 0xffffffffc06b67ec
[245864.699594]  </NMI>

Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
stack trace as absolute address. There is no easy way in case box crashes
as we loose information on load address of specific module.

This changes the symbol decoding (in kernel/module.c) such that it can
print offset from start of section (.text or .init.text) in case there
is no good match with any symbol.

It will now decode address in such cases to [module]+ offset/size or
[module __init]+offset/size depending on where the address lies (in
core/.text or init/.init.text section of module).

One can use objdump/readelf/nm to find symbols with offset from .init.text
and .text sections.

steps to reproduce the problem:
-------------------------------
1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
2. Build and strip the module using --strip-unneeded option
3. Load the module and check RIP in dmesg

tests done:
-----------
1. Added WARN_ON_ONE(1) in functions of a module for testing
-------------------------------------------------------------
[  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
[  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
[  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
[  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
[  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
[  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
[  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
[  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
[  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
[  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
[  407.934113] Call Trace:
[  407.934114]  <TASK>
[  407.934116]  ? init_module+0x55/0xff9 [test_module]
...
[  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
[  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
[  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
[  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
[  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
[  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
[  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
[  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
[  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
[  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
[  407.934260] Call Trace:
[  407.934260]  <TASK>
[  407.934261]  ? init_module+0x5a/0xff9 [test_module]

note that it is able to decode RIP to an offset from module start or
init start now.

tested on linux->next (tag next-20211220)

Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
Acked-by: Nishit Shah <nishit.shah@sophos.com>
Suggested-by: Dirk VanDerMerwe <Dirk.VanDerMerwe@Sophos.com>
---
 kernel/module.c | 44 +++++++++++++++++++++++++++++++++++++++-----
 1 file changed, 39 insertions(+), 5 deletions(-)

diff --git a/kernel/module.c b/kernel/module.c
index 24dab046e16c..635e631c92f1 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -4260,6 +4260,19 @@ static const char *kallsyms_symbol_name(struct mod_kallsyms *kallsyms, unsigned
 	return kallsyms->strtab + kallsyms->symtab[symnum].st_name;
 }
 
+/*
+ * Check if module address (addr) passed is as per init passed
+ * if init is true then check in init layout
+ * else check in core layout
+ */
+bool match_address_layout(struct module *mod, unsigned long addr, bool init)
+{
+	if (init)
+		return within_module_init(addr, mod);
+	else
+		return within_module_core(addr, mod);
+}
+
 /*
  * Given a module and address, find the corresponding symbol and return its name
  * while providing its size and offset if needed.
@@ -4270,14 +4283,22 @@ static const char *find_kallsyms_symbol(struct module *mod,
 					unsigned long *offset)
 {
 	unsigned int i, best = 0;
-	unsigned long nextval, bestval;
+	unsigned long baseval, nextval, bestval;
 	struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
+	char *module_base_name;
+	bool is_init_address = false;
 
 	/* At worse, next value is at end of module */
-	if (within_module_init(addr, mod))
+	if (within_module_init(addr, mod)) {
+		baseval = (unsigned long)mod->init_layout.base;
 		nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
-	else
+		module_base_name = "[module __init]";
+		is_init_address = true;
+	} else {
+		baseval = (unsigned long)mod->core_layout.base;
 		nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
+		module_base_name = "[module]";
+	}
 
 	bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
 
@@ -4300,7 +4321,8 @@ static const char *find_kallsyms_symbol(struct module *mod,
 		    || is_arm_mapping_symbol(kallsyms_symbol_name(kallsyms, i)))
 			continue;
 
-		if (thisval <= addr && thisval > bestval) {
+		if ((thisval <= addr && thisval > bestval) &&
+			(match_address_layout(mod, thisval, is_init_address))) {
 			best = i;
 			bestval = thisval;
 		}
@@ -4308,8 +4330,20 @@ static const char *find_kallsyms_symbol(struct module *mod,
 			nextval = thisval;
 	}
 
-	if (!best)
+	if (!best) {
+		if (is_module_text_address(addr)) {
+			/*
+			 * return MODULE base and offset if we could not find
+			 * any best match for text address
+			 */
+			if (size)
+				*size = nextval - baseval;
+			if (offset)
+				*offset = addr - baseval;
+			return module_base_name;
+		}
 		return NULL;
+	}
 
 	if (size)
 		*size = nextval - bestval;
-- 
2.32.0


^ permalink raw reply related	[flat|nested] 36+ messages in thread

* Re: [PATCH v6] modules: add heuristic when stripping unneeded symbols
  2022-02-08 11:02                                                   ` [PATCH v6] " Vimal Agrawal
@ 2022-02-08 11:13                                                     ` Vimal Agrawal
  2022-02-08 18:10                                                     ` Luis Chamberlain
  1 sibling, 0 replies; 36+ messages in thread
From: Vimal Agrawal @ 2022-02-08 11:13 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Christoph Hellwig, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel, Vimal Agrawal, nishit.shah,
	gregkh, Dirk VanDerMerwe

Hi Luis,

I tried to fix the existing 'best' logic so that my hunk can come
under (!best) in patch v6.

test_module.ko with symbols
============================
vimal@ubuntu2:~/linux-next/linux/lib$ sudo dmesg
[ 4955.983315] test_module: module verification failed: signature
and/or required key missing - tainting kernel
[ 4955.983972] test_module: Hello, world
[ 4955.983975] symbol name for address of test_module_warn_init is
test_module_warn_init+0x0/0x7 [test_module]
[ 4955.983989] symbol name for address of test_module_warn_start is
test_module_warn_start+0x0/0x7 [test_module]
[ 4955.983999] symbol name for address of fun_ptr is
fun_ptr+0x0/0xfffffffffffff000 [test_module]

test_module.ko with symbols stripped using --strip-unneeded
============================================================
vimal@ubuntu2:~/linux-next/linux/lib$ !nm
nm test_module.ko
0000000000000000 r .LC0
0000000000000000 D __this_module
                 U _printk
0000000000000000 T cleanup_module
0000000000000007 T init_module

vimal@ubuntu2:~/linux-next/linux/lib$ sudo dmesg
[ 5043.436960] test_module: Hello, world
[ 5043.436966] symbol name for address of test_module_warn_init is
[module __init]+0x0/0x7 [test_module]
[ 5043.436979] symbol name for address of test_module_warn_start is
[module]+0x0/0x7 [test_module]
[ 5043.436988] symbol name for address of fun_ptr is
cleanup_module+0x1ff9/0xff9 [test_module]

patch in test_module.c used for testing:
diff --git a/lib/test_module.c b/lib/test_module.c
index debd19e35198..068fce67c41a 100644
--- a/lib/test_module.c
+++ b/lib/test_module.c
@@ -14,9 +14,25 @@
 #include <linux/module.h>
 #include <linux/printk.h>

+
+static void test_module_warn_start(int x)
+{
+        if (x) WARN_ON_ONCE(1);
+}
+
+static void (*fun_ptr)(int) = &test_module_warn_start;
+
+static void __init test_module_warn_init(int x)
+{
+        if (x) WARN_ON_ONCE(1);
+}
+
 static int __init test_module_init(void)
 {
        pr_warn("Hello, world\n");
+        printk("symbol name for address of test_module_warn_init is
%pS\n", test_module_warn_init);
+        printk("symbol name for address of test_module_warn_start is
%pS\n", test_module_warn_start);
+        printk("symbol name for address of fun_ptr is %pS\n", &fun_ptr);

        return 0;
 }

Note that it is still not fully correct for fun_ptr ( which is .data
or .ro) as it is resolving to cleanup_module in .text.
To fix this, we need to have information in core_layout for the range
of .data and .text separately or have
something like data_layout for data. That will be beyond the scope of
this patch.

I am not sure why you are not able to reproduce. If you can share the
output of > nm test_module.ko after
stripping and after using my patch for test_module.c then I can
possibly make out. I think kernel configs
should not matter, it is how test_module.ko is built and stripped that
should define this.

Vimal

On Tue, Feb 8, 2022 at 4:32 PM Vimal Agrawal <avimalin@gmail.com> wrote:
>
> If kernel modules are stripped off symbols for some reason then stack
> traces in dmesg do not show symbol name for address. It just prints
> absolute address sometimes (if there is no good match with any symbol)
>
> This was seen with OpenWrt which uses option INSTALL_MOD_STRIP=
> "--strip-unneeded" at kernel/module build/install time, and so modules
> are stripped off unneeded symbols.
>
> [245864.699580]  do_nmi+0x12f/0x370
> [245864.699583]  end_repeat_nmi+0x16/0x50
> [245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
> [245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
> [245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
> [245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
> [245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
> [245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
> [245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
> [245864.699590]  ? 0xffffffffc06b61a0
> [245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
> [245864.699593]  ? 0xffffffffc06b67ec
> [245864.699594]  </NMI>
>
> Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
> stack trace as absolute address. There is no easy way in case box crashes
> as we loose information on load address of specific module.
>
> This changes the symbol decoding (in kernel/module.c) such that it can
> print offset from start of section (.text or .init.text) in case there
> is no good match with any symbol.
>
> It will now decode address in such cases to [module]+ offset/size or
> [module __init]+offset/size depending on where the address lies (in
> core/.text or init/.init.text section of module).
>
> One can use objdump/readelf/nm to find symbols with offset from .init.text
> and .text sections.
>
> steps to reproduce the problem:
> -------------------------------
> 1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
> 2. Build and strip the module using --strip-unneeded option
> 3. Load the module and check RIP in dmesg
>
> tests done:
> -----------
> 1. Added WARN_ON_ONE(1) in functions of a module for testing
> -------------------------------------------------------------
> [  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> [  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
> [  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
> [  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> [  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> [  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> [  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> [  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> [  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> [  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> [  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
> [  407.934113] Call Trace:
> [  407.934114]  <TASK>
> [  407.934116]  ? init_module+0x55/0xff9 [test_module]
> ...
> [  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> [  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
> [  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
> [  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> [  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> [  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> [  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> [  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> [  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> [  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> [  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
> [  407.934260] Call Trace:
> [  407.934260]  <TASK>
> [  407.934261]  ? init_module+0x5a/0xff9 [test_module]
>
> note that it is able to decode RIP to an offset from module start or
> init start now.
>
> tested on linux->next (tag next-20211220)
>
> Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
> Acked-by: Nishit Shah <nishit.shah@sophos.com>
> Suggested-by: Dirk VanDerMerwe <Dirk.VanDerMerwe@Sophos.com>
> ---
>  kernel/module.c | 44 +++++++++++++++++++++++++++++++++++++++-----
>  1 file changed, 39 insertions(+), 5 deletions(-)
>
> diff --git a/kernel/module.c b/kernel/module.c
> index 24dab046e16c..635e631c92f1 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -4260,6 +4260,19 @@ static const char *kallsyms_symbol_name(struct mod_kallsyms *kallsyms, unsigned
>         return kallsyms->strtab + kallsyms->symtab[symnum].st_name;
>  }
>
> +/*
> + * Check if module address (addr) passed is as per init passed
> + * if init is true then check in init layout
> + * else check in core layout
> + */
> +bool match_address_layout(struct module *mod, unsigned long addr, bool init)
> +{
> +       if (init)
> +               return within_module_init(addr, mod);
> +       else
> +               return within_module_core(addr, mod);
> +}
> +
>  /*
>   * Given a module and address, find the corresponding symbol and return its name
>   * while providing its size and offset if needed.
> @@ -4270,14 +4283,22 @@ static const char *find_kallsyms_symbol(struct module *mod,
>                                         unsigned long *offset)
>  {
>         unsigned int i, best = 0;
> -       unsigned long nextval, bestval;
> +       unsigned long baseval, nextval, bestval;
>         struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
> +       char *module_base_name;
> +       bool is_init_address = false;
>
>         /* At worse, next value is at end of module */
> -       if (within_module_init(addr, mod))
> +       if (within_module_init(addr, mod)) {
> +               baseval = (unsigned long)mod->init_layout.base;
>                 nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
> -       else
> +               module_base_name = "[module __init]";
> +               is_init_address = true;
> +       } else {
> +               baseval = (unsigned long)mod->core_layout.base;
>                 nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
> +               module_base_name = "[module]";
> +       }
>
>         bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
>
> @@ -4300,7 +4321,8 @@ static const char *find_kallsyms_symbol(struct module *mod,
>                     || is_arm_mapping_symbol(kallsyms_symbol_name(kallsyms, i)))
>                         continue;
>
> -               if (thisval <= addr && thisval > bestval) {
> +               if ((thisval <= addr && thisval > bestval) &&
> +                       (match_address_layout(mod, thisval, is_init_address))) {
>                         best = i;
>                         bestval = thisval;
>                 }
> @@ -4308,8 +4330,20 @@ static const char *find_kallsyms_symbol(struct module *mod,
>                         nextval = thisval;
>         }
>
> -       if (!best)
> +       if (!best) {
> +               if (is_module_text_address(addr)) {
> +                       /*
> +                        * return MODULE base and offset if we could not find
> +                        * any best match for text address
> +                        */
> +                       if (size)
> +                               *size = nextval - baseval;
> +                       if (offset)
> +                               *offset = addr - baseval;
> +                       return module_base_name;
> +               }
>                 return NULL;
> +       }
>
>         if (size)
>                 *size = nextval - bestval;
> --
> 2.32.0
>

^ permalink raw reply related	[flat|nested] 36+ messages in thread

* Re: [PATCH v5] modules: add heuristic when stripping unneeded symbols
  2022-02-08  4:52                                                 ` Vimal Agrawal
  2022-02-08 11:02                                                   ` [PATCH v6] " Vimal Agrawal
@ 2022-02-08 17:55                                                   ` Luis Chamberlain
  2022-02-08 18:12                                                     ` Vimal Agrawal
  1 sibling, 1 reply; 36+ messages in thread
From: Luis Chamberlain @ 2022-02-08 17:55 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: Christoph Hellwig, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel, nishit.shah, Vimal Agrawal,
	Dirk VanDerMerwe, gregkh

On Tue, Feb 08, 2022 at 10:22:06AM +0530, Vimal Agrawal wrote:
> > > Actually I had it  under (!best) in my first patch. I had to change it
> > > because it was resolving the address to symbols like __this_module for
> > > init address at times which is not correct for text address.
> >
> > Can you say that again?
> 
> I hit this a few times later after the first patch. Basically there
> are all symbols in symbol table and best could be none zero ( means it
> matched some symbol) but it may not be match to .text symbol for text
> address ( esp. when --strip-unneeded is used as there are very few
> symbols left after stripping)

You are saying that sometimes having "best" evaluated to non zero
yields incorrect results, where the symbol found is actualy not a .text
symbol for a text address? If so, is this really true for cases where
no stripping is used? If so this is bigger news and I'd like to address
this separately in another commit but we need proof, not just
speculation.

And you seem to be suggesting that this seems to hold more true when
"--strip-unneeded" is used given there are fewer symbols left after
striping?

Did I comprehend what you are trying to say correctly?

> > OK so you're saying sometimes "best" is not true when we use
> > INSTALL_MOD_STRIP="--strip-unneeded"? This is news.
> >
> yes, best can be non zero and may not resolve to .text address when
> --strip-unneeded is used. 

OK.

> without stripping, it will definitely
> resolve to some .text address closely matching in case of no stripping

OK so there is no issue when stripping is used.

> but it can go wrong with stripping. I have seen it a few times post
> the first patch during testing.

OK then we need to take care your added heuristics do not affect
non-stripping.

> > In particulr you seem to be suggesting that if --strip-unneeded was
> > used "best" could be incorrect for !is_module_text_address().
> >
> best could be incorrect even for text address when --strip-unneeded is used.
> e.g. in my case, it is resolving .init.text address to __this_module

You should be explicit about this in your commit log.

> > In any case, you completely changed things in your patch and did not
> > mention *any* of this in your follow up patch, leaving me to question
> > the validity of all this work.
> >
> The Only change I did from the first patch was to move this hunk out of (!best).
> Yes, I missed commenting it in the code.

When you submit a v2 patch and you change something like that you must
clarify changes which are not clear either in the commit log or below
the --- lines after the diffstat and before the actual patch. Each new
patch iteration should have a set of bullets with all the changes you
have made so that the maintainer can track what you have done
differently on each iteration.

Right now you are not making any of this easy on me so I ask that you
stop submitting new patches willy nilly until we have actualy discussed
each item, and we decide what to do. I also ask that you keep track of
each change you are making on each new patch iteration on the patch
after the --- lines and before the patch, so I can easily tell all the
changes you have made on each new iteration.

  Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v6] modules: add heuristic when stripping unneeded symbols
  2022-02-08 11:02                                                   ` [PATCH v6] " Vimal Agrawal
  2022-02-08 11:13                                                     ` Vimal Agrawal
@ 2022-02-08 18:10                                                     ` Luis Chamberlain
  2022-02-08 18:25                                                       ` Vimal Agrawal
  1 sibling, 1 reply; 36+ messages in thread
From: Luis Chamberlain @ 2022-02-08 18:10 UTC (permalink / raw)
  To: Vimal Agrawal
  Cc: hch, masahiroy, michal.lkml, ndesaulniers, JBeulich, jeffm, sam,
	linux-kbuild, jeyu, linux-kernel, vimal.agrawal, nishit.shah,
	gregkh, Dirk VanDerMerwe

On Tue, Feb 08, 2022 at 04:32:31PM +0530, Vimal Agrawal wrote:
> If kernel modules are stripped off symbols for some reason 

For some reason? Are you kidding? It is by design.

> then stack
> traces in dmesg do not show symbol name for address. It just prints
> absolute address sometimes (if there is no good match with any symbol)

Yes that is by design.

> This was seen with OpenWrt which uses option INSTALL_MOD_STRIP=
> "--strip-unneeded" at kernel/module build/install time, and so modules
> are stripped off unneeded symbols.
> 
> [245864.699580]  do_nmi+0x12f/0x370
> [245864.699583]  end_repeat_nmi+0x16/0x50
> [245864.699585] RIP: 0010:0xffffffffc06b67ec                           <<<<<<<<
> [245864.699585] RSP: 0000:ffffaaa540cffe48 EFLAGS: 00000097
> [245864.699586] RAX: 0000000000000001 RBX: ffff93357a729000 RCX: 0000000000000001
> [245864.699587] RDX: ffff93357a729050 RSI: 0000000000000000 RDI: ffff93357a729000
> [245864.699588] RBP: ffff9335cf521300 R08: 0000000000000001 R09: 0000000000000004
> [245864.699588] R10: ffffaaa545b23ed0 R11: 0000000000000001 R12: ffffffffc06b61a0
> [245864.699589] R13: ffffaaa540cffe60 R14: ffff9335c77fa3c0 R15: ffff9335cf51d7c0
> [245864.699590]  ? 0xffffffffc06b61a0
> [245864.699592]  ? 0xffffffffc06b67ec                                  <<<<<<<<
> [245864.699593]  ? 0xffffffffc06b67ec
> [245864.699594]  </NMI>
> 
> Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
> stack trace as absolute address. There is no easy way in case box crashes
> as we loose information on load address of specific module.

Mentioning this note makes little sense, just say how the above doesn't help you
easily identify the root cause of an address, and how this is just part
of consequences of stripping symbols. Because developers using
INSTALL_MOD_STRIP="--strip-unneeded"  know that they are trading off
debugging live crashes over reducing the kernel and module binary size.

> This changes the symbol decoding (in kernel/module.c) such that it can
> print offset from start of section (.text or .init.text) in case there
> is no good match with any symbol.

No, this is adding a new heuristic to help in cases where no good match
for a symbol was found, and typically this can be when symbols are
stripped.

> It will now decode address in such cases to [module]+ offset/size or
> [module __init]+offset/size depending on where the address lies (in
> core/.text or init/.init.text section of module).
> 
> One can use objdump/readelf/nm to find symbols with offset from .init.text
> and .text sections.
> 
> steps to reproduce the problem:
> -------------------------------
> 1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
> 2. Build and strip the module using --strip-unneeded option
> 3. Load the module and check RIP in dmesg
> 
> tests done:
> -----------
> 1. Added WARN_ON_ONE(1) in functions of a module for testing
> -------------------------------------------------------------
> [  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> [  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
> [  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
> [  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> [  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> [  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> [  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> [  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> [  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> [  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> [  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
> [  407.934113] Call Trace:
> [  407.934114]  <TASK>
> [  407.934116]  ? init_module+0x55/0xff9 [test_module]
> ...
> [  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> [  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> [  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
> [  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
> [  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> [  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> [  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> [  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> [  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> [  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> [  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> [  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
> [  407.934260] Call Trace:
> [  407.934260]  <TASK>
> [  407.934261]  ? init_module+0x5a/0xff9 [test_module]
> 
> note that it is able to decode RIP to an offset from module start or
> init start now.
> 
> tested on linux->next (tag next-20211220)
> 
> Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
> Acked-by: Nishit Shah <nishit.shah@sophos.com>
> Suggested-by: Dirk VanDerMerwe <Dirk.VanDerMerwe@Sophos.com>
> ---
>  kernel/module.c | 44 +++++++++++++++++++++++++++++++++++++++-----
>  1 file changed, 39 insertions(+), 5 deletions(-)
> 
> diff --git a/kernel/module.c b/kernel/module.c
> index 24dab046e16c..635e631c92f1 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -4260,6 +4260,19 @@ static const char *kallsyms_symbol_name(struct mod_kallsyms *kallsyms, unsigned
>  	return kallsyms->strtab + kallsyms->symtab[symnum].st_name;
>  }
>  
> +/*
> + * Check if module address (addr) passed is as per init passed
> + * if init is true then check in init layout
> + * else check in core layout
> + */
> +bool match_address_layout(struct module *mod, unsigned long addr, bool init)
> +{
> +	if (init)
> +		return within_module_init(addr, mod);
> +	else
> +		return within_module_core(addr, mod);
> +}
> +
>  /*
>   * Given a module and address, find the corresponding symbol and return its name
>   * while providing its size and offset if needed.
> @@ -4270,14 +4283,22 @@ static const char *find_kallsyms_symbol(struct module *mod,
>  					unsigned long *offset)
>  {
>  	unsigned int i, best = 0;
> -	unsigned long nextval, bestval;
> +	unsigned long baseval, nextval, bestval;
>  	struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
> +	char *module_base_name;
> +	bool is_init_address = false;
>  
>  	/* At worse, next value is at end of module */
> -	if (within_module_init(addr, mod))
> +	if (within_module_init(addr, mod)) {
> +		baseval = (unsigned long)mod->init_layout.base;
>  		nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
> -	else
> +		module_base_name = "[module __init]";
> +		is_init_address = true;
> +	} else {
> +		baseval = (unsigned long)mod->core_layout.base;
>  		nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
> +		module_base_name = "[module]";
> +	}
>  


To make all this readible and easier to follow please break down your
work into 3 patches:

1) You add the above branch and add baseval as you do now and you also
use it on the nextval assigmment. So something like this:

+             baseval = (unsigned long)mod->init_layout.base;                 
-             nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
+             nextval = baseval + mod->init_layout.text_size;

You would do that for the core_layout branch too.

This would make only one single change to the code. That is just one
patch. And that patch introduces no functional changes. You would
clarify that on the commit log, to make it clear there is no possible
regression risks with it.

>  	bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
>  
> @@ -4300,7 +4321,8 @@ static const char *find_kallsyms_symbol(struct module *mod,
>  		    || is_arm_mapping_symbol(kallsyms_symbol_name(kallsyms, i)))
>  			continue;
>  
> -		if (thisval <= addr && thisval > bestval) {
> +		if ((thisval <= addr && thisval > bestval) &&
> +			(match_address_layout(mod, thisval, is_init_address))) {

OK your 2nd patch will be:

2) You add match_address_layout() and the is_init_address bool. This is
a fix found through code inspection. You can clarify that the issue has
only been found when --strip-unneeded is used, however, that the fix
could potentialy solve other false symbol. At this point in time no
known cases are known where the reported symbol returned is invalid,
but this sanity check makes sense even for cases where no striping is
used. You can also mention that you this fix is also being added to
be able to add a new heuristic later for cases where --strip-unneeded
is used.

>  			best = i;
>  			bestval = thisval;
>  		}
> @@ -4308,8 +4330,20 @@ static const char *find_kallsyms_symbol(struct module *mod,
>  			nextval = thisval;
>  	}
>  
> -	if (!best)
> +	if (!best) {
> +		if (is_module_text_address(addr)) {
> +			/*
> +			 * return MODULE base and offset if we could not find
> +			 * any best match for text address
> +			 */
> +			if (size)
> +				*size = nextval - baseval;
> +			if (offset)
> +				*offset = addr - baseval;
> +			return module_base_name;
> +		}
>  		return NULL;

And then patch 3 is this new change. Please test the config I sent you
though, I have not been able to reproduce your setup yet.

  Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v5] modules: add heuristic when stripping unneeded symbols
  2022-02-08 17:55                                                   ` [PATCH v5] " Luis Chamberlain
@ 2022-02-08 18:12                                                     ` Vimal Agrawal
  0 siblings, 0 replies; 36+ messages in thread
From: Vimal Agrawal @ 2022-02-08 18:12 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Christoph Hellwig, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel, nishit.shah, Vimal Agrawal,
	Dirk VanDerMerwe, gregkh

> You are saying that sometimes having "best" evaluated to non zero
> yields incorrect results, where the symbol found is actualy not a .text
> symbol for a text address? If so, is this really true for cases where
> no stripping is used? If so this is bigger news and I'd like to address
> this separately in another commit but we need proof, not just
> speculation.
>
I have not seen this issue without stripping so far as in that case it will find
some better match with some .text address but I have seen this consistently
with stripping.

> And you seem to be suggesting that this seems to hold more true when
> "--strip-unneeded" is used given there are fewer symbols left after
> striping?
>
yes. This is seen with stripping only.

> > without stripping, it will definitely
> > resolve to some .text address closely matching in case of no stripping
>
> OK so there is no issue when stripping is used.
>
yes. I assume you meant when stripping is not used.

> > but it can go wrong with stripping. I have seen it a few times post
> > the first patch during testing.
>
> OK then we need to take care your added heuristics do not affect
> non-stripping.
>
yes. so I tested .init , .text and one data address (without being
stripped) to make
sure there is no affect. Attached the result in my previous mail.

> > best could be incorrect even for text address when --strip-unneeded is used.
> > e.g. in my case, it is resolving .init.text address to __this_module
>
> You should be explicit about this in your commit log.
>
Ok

> When you submit a v2 patch and you change something like that you must
> clarify changes which are not clear either in the commit log or below
> the --- lines after the diffstat and before the actual patch. Each new
> patch iteration should have a set of bullets with all the changes you
> have made so that the maintainer can track what you have done
> differently on each iteration.
>
> Right now you are not making any of this easy on me so I ask that you
> stop submitting new patches willy nilly until we have actualy discussed
> each item, and we decide what to do. I also ask that you keep track of
> each change you are making on each new patch iteration on the patch
> after the --- lines and before the patch, so I can easily tell all the
> changes you have made on each new iteration.
>
Sure. Thanks for educating me.

>   Luis

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v6] modules: add heuristic when stripping unneeded symbols
  2022-02-08 18:10                                                     ` Luis Chamberlain
@ 2022-02-08 18:25                                                       ` Vimal Agrawal
  2022-02-25  7:59                                                         ` Vimal Agrawal
  0 siblings, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2022-02-08 18:25 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Christoph Hellwig, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel, Vimal Agrawal, nishit.shah,
	gregkh, Dirk VanDerMerwe

> > If kernel modules are stripped off symbols for some reason
>
> For some reason? Are you kidding? It is by design.
>
I meant that symbols can be stripped for various reasons e.g. if
stripped using --strip-unneeded option.

> > then stack
> > traces in dmesg do not show symbol name for address. It just prints
> > absolute address sometimes (if there is no good match with any symbol)
>
> Yes that is by design.
>
but we can improve it to show the offset from init start or core start
which can help for decoding later.

> > Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
> > stack trace as absolute address. There is no easy way in case box crashes
> > as we loose information on load address of specific module.
>
> Mentioning this note makes little sense, just say how the above doesn't help you
> easily identify the root cause of an address, and how this is just part
> of consequences of stripping symbols. Because developers using
> INSTALL_MOD_STRIP="--strip-unneeded"  know that they are trading off
> debugging live crashes over reducing the kernel and module binary size.
>
Ok

> > This changes the symbol decoding (in kernel/module.c) such that it can
> > print offset from start of section (.text or .init.text) in case there
> > is no good match with any symbol.
>
> No, this is adding a new heuristic to help in cases where no good match
> for a symbol was found, and typically this can be when symbols are
> stripped.
>
Ok
> > It will now decode address in such cases to [module]+ offset/size or
> > [module __init]+offset/size depending on where the address lies (in
> > core/.text or init/.init.text section of module).
> >
> > One can use objdump/readelf/nm to find symbols with offset from .init.text
> > and .text sections.
> >
> > steps to reproduce the problem:
> > -------------------------------
> > 1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
> > 2. Build and strip the module using --strip-unneeded option
> > 3. Load the module and check RIP in dmesg
> >
> > tests done:
> > -----------
> > 1. Added WARN_ON_ONE(1) in functions of a module for testing
> > -------------------------------------------------------------
> > [  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> > [  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> > [  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
> > [  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
> > [  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> > [  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> > [  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> > [  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> > [  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> > [  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> > [  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> > [  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
> > [  407.934113] Call Trace:
> > [  407.934114]  <TASK>
> > [  407.934116]  ? init_module+0x55/0xff9 [test_module]
> > ...
> > [  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> > [  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> > [  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
> > [  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
> > [  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> > [  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> > [  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> > [  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> > [  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> > [  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> > [  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> > [  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
> > [  407.934260] Call Trace:
> > [  407.934260]  <TASK>
> > [  407.934261]  ? init_module+0x5a/0xff9 [test_module]
> >
> > note that it is able to decode RIP to an offset from module start or
> > init start now.
> >
> > tested on linux->next (tag next-20211220)
> >
> > Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
> > Acked-by: Nishit Shah <nishit.shah@sophos.com>
> > Suggested-by: Dirk VanDerMerwe <Dirk.VanDerMerwe@Sophos.com>
> > ---
> >  kernel/module.c | 44 +++++++++++++++++++++++++++++++++++++++-----
> >  1 file changed, 39 insertions(+), 5 deletions(-)
> >
> > diff --git a/kernel/module.c b/kernel/module.c
> > index 24dab046e16c..635e631c92f1 100644
> > --- a/kernel/module.c
> > +++ b/kernel/module.c
> > @@ -4260,6 +4260,19 @@ static const char *kallsyms_symbol_name(struct mod_kallsyms *kallsyms, unsigned
> >       return kallsyms->strtab + kallsyms->symtab[symnum].st_name;
> >  }
> >
> > +/*
> > + * Check if module address (addr) passed is as per init passed
> > + * if init is true then check in init layout
> > + * else check in core layout
> > + */
> > +bool match_address_layout(struct module *mod, unsigned long addr, bool init)
> > +{
> > +     if (init)
> > +             return within_module_init(addr, mod);
> > +     else
> > +             return within_module_core(addr, mod);
> > +}
> > +
> >  /*
> >   * Given a module and address, find the corresponding symbol and return its name
> >   * while providing its size and offset if needed.
> > @@ -4270,14 +4283,22 @@ static const char *find_kallsyms_symbol(struct module *mod,
> >                                       unsigned long *offset)
> >  {
> >       unsigned int i, best = 0;
> > -     unsigned long nextval, bestval;
> > +     unsigned long baseval, nextval, bestval;
> >       struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
> > +     char *module_base_name;
> > +     bool is_init_address = false;
> >
> >       /* At worse, next value is at end of module */
> > -     if (within_module_init(addr, mod))
> > +     if (within_module_init(addr, mod)) {
> > +             baseval = (unsigned long)mod->init_layout.base;
> >               nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
> > -     else
> > +             module_base_name = "[module __init]";
> > +             is_init_address = true;
> > +     } else {
> > +             baseval = (unsigned long)mod->core_layout.base;
> >               nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
> > +             module_base_name = "[module]";
> > +     }
> >
>
>
> To make all this readible and easier to follow please break down your
> work into 3 patches:
>
> 1) You add the above branch and add baseval as you do now and you also
> use it on the nextval assigmment. So something like this:
>
> +             baseval = (unsigned long)mod->init_layout.base;
> -             nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
> +             nextval = baseval + mod->init_layout.text_size;
>
> You would do that for the core_layout branch too.
>
> This would make only one single change to the code. That is just one
> patch. And that patch introduces no functional changes. You would
> clarify that on the commit log, to make it clear there is no possible
> regression risks with it.
>
> >       bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
> >
> > @@ -4300,7 +4321,8 @@ static const char *find_kallsyms_symbol(struct module *mod,
> >                   || is_arm_mapping_symbol(kallsyms_symbol_name(kallsyms, i)))
> >                       continue;
> >
> > -             if (thisval <= addr && thisval > bestval) {
> > +             if ((thisval <= addr && thisval > bestval) &&
> > +                     (match_address_layout(mod, thisval, is_init_address))) {
>
> OK your 2nd patch will be:
>
> 2) You add match_address_layout() and the is_init_address bool. This is
> a fix found through code inspection. You can clarify that the issue has
> only been found when --strip-unneeded is used, however, that the fix
> could potentialy solve other false symbol. At this point in time no
> known cases are known where the reported symbol returned is invalid,
> but this sanity check makes sense even for cases where no striping is
> used. You can also mention that you this fix is also being added to
> be able to add a new heuristic later for cases where --strip-unneeded
> is used.
>
> >                       best = i;
> >                       bestval = thisval;
> >               }
> > @@ -4308,8 +4330,20 @@ static const char *find_kallsyms_symbol(struct module *mod,
> >                       nextval = thisval;
> >       }
> >
> > -     if (!best)
> > +     if (!best) {
> > +             if (is_module_text_address(addr)) {
> > +                     /*
> > +                      * return MODULE base and offset if we could not find
> > +                      * any best match for text address
> > +                      */
> > +                     if (size)
> > +                             *size = nextval - baseval;
> > +                     if (offset)
> > +                             *offset = addr - baseval;
> > +                     return module_base_name;
> > +             }
> >               return NULL;
>
> And then patch 3 is this new change. Please test the config I sent you
> though, I have not been able to reproduce your setup yet.
>
>   Luis
sure I will do as suggested. Thanks.

Vimal

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v6] modules: add heuristic when stripping unneeded symbols
  2022-02-08 18:25                                                       ` Vimal Agrawal
@ 2022-02-25  7:59                                                         ` Vimal Agrawal
  2022-02-25 13:40                                                           ` Vimal Agrawal
  0 siblings, 1 reply; 36+ messages in thread
From: Vimal Agrawal @ 2022-02-25  7:59 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Christoph Hellwig, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel, Vimal Agrawal, nishit.shah,
	gregkh, Dirk VanDerMerwe

Hi Luis,

I tested with the latest linux->next on KVM VM ( on AWS) and results
are the same. Haven't tried with your .config yet.

[ec2-user@ip-172-31-22-235 lib]$ uname -ra
Linux ip-172-31-22-235.ec2.internal 5.17.0-rc5+ #7 SMP PREEMPT Fri Feb
25 07:14:03 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

1. without patch
=================
a) with symbols
-----------------
[ 2050.306916] symbol name for address of test_module_warn_init is
test_module_warn_init+0x0/0x7 [test_module]
[ 2050.311348] symbol name for address of test_module_warn_start is
test_module_warn_start+0x0/0x8 [test_module]
[ 2050.315921] symbol name for address of fun_ptr is
fun_ptr+0x0/0xfffffffffffff000 [test_module]

b) with stripping using --strip-unneeded option
--------------------------------------------
[ 2131.639375] symbol name for address of test_module_warn_init is
__this_module+0x2fc0/0x2fc7 [test_module]
[ 2131.643739] symbol name for address of test_module_warn_start is
0xffffffffc01b3000
[ 2131.647302] symbol name for address of fun_ptr is
cleanup_module+0x1ff8/0xff8 [test_module]

2. with patch
==============
a) with symbols
-----------------
[  512.937924] symbol name for address of test_module_warn_init is
test_module_warn_init+0x0/0x7 [test_module]
[  512.942388] symbol name for address of test_module_warn_start is
test_module_warn_start+0x0/0x8 [test_module]
[  512.978506] symbol name for address of fun_ptr is
fun_ptr+0x0/0xfffffffffffff000 [test_module]

b) with stripping using --strip-unneeded option
--------------------------------------------
[  171.976330] symbol name for address of test_module_warn_init is
[module __init]+0x0/0x7 [test_module]
[  171.980682] symbol name for address of test_module_warn_start is
[module]+0x0/0x8 [test_module]
[  172.074418] symbol name for address of fun_ptr is
cleanup_module+0x1ff8/0xff8 [test_module]

It is still broken for fun_ptr which is outside the scope of this
patch as I mentioned earlier.

Vimal

On Tue, Feb 8, 2022 at 11:55 PM Vimal Agrawal <avimalin@gmail.com> wrote:
>
> > > If kernel modules are stripped off symbols for some reason
> >
> > For some reason? Are you kidding? It is by design.
> >
> I meant that symbols can be stripped for various reasons e.g. if
> stripped using --strip-unneeded option.
>
> > > then stack
> > > traces in dmesg do not show symbol name for address. It just prints
> > > absolute address sometimes (if there is no good match with any symbol)
> >
> > Yes that is by design.
> >
> but we can improve it to show the offset from init start or core start
> which can help for decoding later.
>
> > > Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
> > > stack trace as absolute address. There is no easy way in case box crashes
> > > as we loose information on load address of specific module.
> >
> > Mentioning this note makes little sense, just say how the above doesn't help you
> > easily identify the root cause of an address, and how this is just part
> > of consequences of stripping symbols. Because developers using
> > INSTALL_MOD_STRIP="--strip-unneeded"  know that they are trading off
> > debugging live crashes over reducing the kernel and module binary size.
> >
> Ok
>
> > > This changes the symbol decoding (in kernel/module.c) such that it can
> > > print offset from start of section (.text or .init.text) in case there
> > > is no good match with any symbol.
> >
> > No, this is adding a new heuristic to help in cases where no good match
> > for a symbol was found, and typically this can be when symbols are
> > stripped.
> >
> Ok
> > > It will now decode address in such cases to [module]+ offset/size or
> > > [module __init]+offset/size depending on where the address lies (in
> > > core/.text or init/.init.text section of module).
> > >
> > > One can use objdump/readelf/nm to find symbols with offset from .init.text
> > > and .text sections.
> > >
> > > steps to reproduce the problem:
> > > -------------------------------
> > > 1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
> > > 2. Build and strip the module using --strip-unneeded option
> > > 3. Load the module and check RIP in dmesg
> > >
> > > tests done:
> > > -----------
> > > 1. Added WARN_ON_ONE(1) in functions of a module for testing
> > > -------------------------------------------------------------
> > > [  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> > > [  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> > > [  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
> > > [  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
> > > [  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> > > [  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> > > [  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> > > [  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> > > [  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> > > [  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> > > [  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> > > [  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > > [  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
> > > [  407.934113] Call Trace:
> > > [  407.934114]  <TASK>
> > > [  407.934116]  ? init_module+0x55/0xff9 [test_module]
> > > ...
> > > [  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> > > [  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> > > [  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
> > > [  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
> > > [  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> > > [  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> > > [  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> > > [  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> > > [  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> > > [  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> > > [  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> > > [  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > > [  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
> > > [  407.934260] Call Trace:
> > > [  407.934260]  <TASK>
> > > [  407.934261]  ? init_module+0x5a/0xff9 [test_module]
> > >
> > > note that it is able to decode RIP to an offset from module start or
> > > init start now.
> > >
> > > tested on linux->next (tag next-20211220)
> > >
> > > Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
> > > Acked-by: Nishit Shah <nishit.shah@sophos.com>
> > > Suggested-by: Dirk VanDerMerwe <Dirk.VanDerMerwe@Sophos.com>
> > > ---
> > >  kernel/module.c | 44 +++++++++++++++++++++++++++++++++++++++-----
> > >  1 file changed, 39 insertions(+), 5 deletions(-)
> > >
> > > diff --git a/kernel/module.c b/kernel/module.c
> > > index 24dab046e16c..635e631c92f1 100644
> > > --- a/kernel/module.c
> > > +++ b/kernel/module.c
> > > @@ -4260,6 +4260,19 @@ static const char *kallsyms_symbol_name(struct mod_kallsyms *kallsyms, unsigned
> > >       return kallsyms->strtab + kallsyms->symtab[symnum].st_name;
> > >  }
> > >
> > > +/*
> > > + * Check if module address (addr) passed is as per init passed
> > > + * if init is true then check in init layout
> > > + * else check in core layout
> > > + */
> > > +bool match_address_layout(struct module *mod, unsigned long addr, bool init)
> > > +{
> > > +     if (init)
> > > +             return within_module_init(addr, mod);
> > > +     else
> > > +             return within_module_core(addr, mod);
> > > +}
> > > +
> > >  /*
> > >   * Given a module and address, find the corresponding symbol and return its name
> > >   * while providing its size and offset if needed.
> > > @@ -4270,14 +4283,22 @@ static const char *find_kallsyms_symbol(struct module *mod,
> > >                                       unsigned long *offset)
> > >  {
> > >       unsigned int i, best = 0;
> > > -     unsigned long nextval, bestval;
> > > +     unsigned long baseval, nextval, bestval;
> > >       struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
> > > +     char *module_base_name;
> > > +     bool is_init_address = false;
> > >
> > >       /* At worse, next value is at end of module */
> > > -     if (within_module_init(addr, mod))
> > > +     if (within_module_init(addr, mod)) {
> > > +             baseval = (unsigned long)mod->init_layout.base;
> > >               nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
> > > -     else
> > > +             module_base_name = "[module __init]";
> > > +             is_init_address = true;
> > > +     } else {
> > > +             baseval = (unsigned long)mod->core_layout.base;
> > >               nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
> > > +             module_base_name = "[module]";
> > > +     }
> > >
> >
> >
> > To make all this readible and easier to follow please break down your
> > work into 3 patches:
> >
> > 1) You add the above branch and add baseval as you do now and you also
> > use it on the nextval assigmment. So something like this:
> >
> > +             baseval = (unsigned long)mod->init_layout.base;
> > -             nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
> > +             nextval = baseval + mod->init_layout.text_size;
> >
> > You would do that for the core_layout branch too.
> >
> > This would make only one single change to the code. That is just one
> > patch. And that patch introduces no functional changes. You would
> > clarify that on the commit log, to make it clear there is no possible
> > regression risks with it.
> >
> > >       bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
> > >
> > > @@ -4300,7 +4321,8 @@ static const char *find_kallsyms_symbol(struct module *mod,
> > >                   || is_arm_mapping_symbol(kallsyms_symbol_name(kallsyms, i)))
> > >                       continue;
> > >
> > > -             if (thisval <= addr && thisval > bestval) {
> > > +             if ((thisval <= addr && thisval > bestval) &&
> > > +                     (match_address_layout(mod, thisval, is_init_address))) {
> >
> > OK your 2nd patch will be:
> >
> > 2) You add match_address_layout() and the is_init_address bool. This is
> > a fix found through code inspection. You can clarify that the issue has
> > only been found when --strip-unneeded is used, however, that the fix
> > could potentialy solve other false symbol. At this point in time no
> > known cases are known where the reported symbol returned is invalid,
> > but this sanity check makes sense even for cases where no striping is
> > used. You can also mention that you this fix is also being added to
> > be able to add a new heuristic later for cases where --strip-unneeded
> > is used.
> >
> > >                       best = i;
> > >                       bestval = thisval;
> > >               }
> > > @@ -4308,8 +4330,20 @@ static const char *find_kallsyms_symbol(struct module *mod,
> > >                       nextval = thisval;
> > >       }
> > >
> > > -     if (!best)
> > > +     if (!best) {
> > > +             if (is_module_text_address(addr)) {
> > > +                     /*
> > > +                      * return MODULE base and offset if we could not find
> > > +                      * any best match for text address
> > > +                      */
> > > +                     if (size)
> > > +                             *size = nextval - baseval;
> > > +                     if (offset)
> > > +                             *offset = addr - baseval;
> > > +                     return module_base_name;
> > > +             }
> > >               return NULL;
> >
> > And then patch 3 is this new change. Please test the config I sent you
> > though, I have not been able to reproduce your setup yet.
> >
> >   Luis
> sure I will do as suggested. Thanks.
>
> Vimal

^ permalink raw reply	[flat|nested] 36+ messages in thread

* Re: [PATCH v6] modules: add heuristic when stripping unneeded symbols
  2022-02-25  7:59                                                         ` Vimal Agrawal
@ 2022-02-25 13:40                                                           ` Vimal Agrawal
  0 siblings, 0 replies; 36+ messages in thread
From: Vimal Agrawal @ 2022-02-25 13:40 UTC (permalink / raw)
  To: Luis Chamberlain
  Cc: Christoph Hellwig, Masahiro Yamada, Michal Marek,
	Nick Desaulniers, Jan Beulich, Jeff Mahoney, Sam Ravnborg,
	linux-kbuild, jeyu, linux-kernel, Vimal Agrawal, nishit.shah,
	gregkh, Dirk VanDerMerwe

Hi Luis,

I tried with your config as well using make oldconfig. It has the same results.

Vimal

On Fri, Feb 25, 2022 at 1:29 PM Vimal Agrawal <avimalin@gmail.com> wrote:
>
> Hi Luis,
>
> I tested with the latest linux->next on KVM VM ( on AWS) and results
> are the same. Haven't tried with your .config yet.
>
> [ec2-user@ip-172-31-22-235 lib]$ uname -ra
> Linux ip-172-31-22-235.ec2.internal 5.17.0-rc5+ #7 SMP PREEMPT Fri Feb
> 25 07:14:03 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
>
> 1. without patch
> =================
> a) with symbols
> -----------------
> [ 2050.306916] symbol name for address of test_module_warn_init is
> test_module_warn_init+0x0/0x7 [test_module]
> [ 2050.311348] symbol name for address of test_module_warn_start is
> test_module_warn_start+0x0/0x8 [test_module]
> [ 2050.315921] symbol name for address of fun_ptr is
> fun_ptr+0x0/0xfffffffffffff000 [test_module]
>
> b) with stripping using --strip-unneeded option
> --------------------------------------------
> [ 2131.639375] symbol name for address of test_module_warn_init is
> __this_module+0x2fc0/0x2fc7 [test_module]
> [ 2131.643739] symbol name for address of test_module_warn_start is
> 0xffffffffc01b3000
> [ 2131.647302] symbol name for address of fun_ptr is
> cleanup_module+0x1ff8/0xff8 [test_module]
>
> 2. with patch
> ==============
> a) with symbols
> -----------------
> [  512.937924] symbol name for address of test_module_warn_init is
> test_module_warn_init+0x0/0x7 [test_module]
> [  512.942388] symbol name for address of test_module_warn_start is
> test_module_warn_start+0x0/0x8 [test_module]
> [  512.978506] symbol name for address of fun_ptr is
> fun_ptr+0x0/0xfffffffffffff000 [test_module]
>
> b) with stripping using --strip-unneeded option
> --------------------------------------------
> [  171.976330] symbol name for address of test_module_warn_init is
> [module __init]+0x0/0x7 [test_module]
> [  171.980682] symbol name for address of test_module_warn_start is
> [module]+0x0/0x8 [test_module]
> [  172.074418] symbol name for address of fun_ptr is
> cleanup_module+0x1ff8/0xff8 [test_module]
>
> It is still broken for fun_ptr which is outside the scope of this
> patch as I mentioned earlier.
>
> Vimal
>
> On Tue, Feb 8, 2022 at 11:55 PM Vimal Agrawal <avimalin@gmail.com> wrote:
> >
> > > > If kernel modules are stripped off symbols for some reason
> > >
> > > For some reason? Are you kidding? It is by design.
> > >
> > I meant that symbols can be stripped for various reasons e.g. if
> > stripped using --strip-unneeded option.
> >
> > > > then stack
> > > > traces in dmesg do not show symbol name for address. It just prints
> > > > absolute address sometimes (if there is no good match with any symbol)
> > >
> > > Yes that is by design.
> > >
> > but we can improve it to show the offset from init start or core start
> > which can help for decoding later.
> >
> > > > Note RIP: 0010:0xffffffffc06b67ec and 0xffffffffc06b67ec printed in above
> > > > stack trace as absolute address. There is no easy way in case box crashes
> > > > as we loose information on load address of specific module.
> > >
> > > Mentioning this note makes little sense, just say how the above doesn't help you
> > > easily identify the root cause of an address, and how this is just part
> > > of consequences of stripping symbols. Because developers using
> > > INSTALL_MOD_STRIP="--strip-unneeded"  know that they are trading off
> > > debugging live crashes over reducing the kernel and module binary size.
> > >
> > Ok
> >
> > > > This changes the symbol decoding (in kernel/module.c) such that it can
> > > > print offset from start of section (.text or .init.text) in case there
> > > > is no good match with any symbol.
> > >
> > > No, this is adding a new heuristic to help in cases where no good match
> > > for a symbol was found, and typically this can be when symbols are
> > > stripped.
> > >
> > Ok
> > > > It will now decode address in such cases to [module]+ offset/size or
> > > > [module __init]+offset/size depending on where the address lies (in
> > > > core/.text or init/.init.text section of module).
> > > >
> > > > One can use objdump/readelf/nm to find symbols with offset from .init.text
> > > > and .text sections.
> > > >
> > > > steps to reproduce the problem:
> > > > -------------------------------
> > > > 1. Add WARN_ON_ONCE(1) in module e.g. test_module.c
> > > > 2. Build and strip the module using --strip-unneeded option
> > > > 3. Load the module and check RIP in dmesg
> > > >
> > > > tests done:
> > > > -----------
> > > > 1. Added WARN_ON_ONE(1) in functions of a module for testing
> > > > -------------------------------------------------------------
> > > > [  407.934085] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> > > > [  407.934087] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> > > > [  407.934088] RIP: 0010:[module __init]+0x4/0x7 [test_module]
> > > > [  407.934097] Code: Unable to access opcode bytes at RIP 0xffffffffc07edfda.
> > > > [  407.934098] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> > > > [  407.934100] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> > > > [  407.934101] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> > > > [  407.934102] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> > > > [  407.934103] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> > > > [  407.934104] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> > > > [  407.934105] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> > > > [  407.934107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > > > [  407.934108] CR2: ffffffffc07edfda CR3: 00000000063ea006 CR4: 00000000000706f0
> > > > [  407.934113] Call Trace:
> > > > [  407.934114]  <TASK>
> > > > [  407.934116]  ? init_module+0x55/0xff9 [test_module]
> > > > ...
> > > > [  407.934232] CPU: 0 PID: 2956 Comm: insmod Tainted: G        W   E     5.16.0-rc5-next-20211220+ #2
> > > > [  407.934234] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
> > > > [  407.934242] RIP: 0010:[module]+0x4/0x7 [test_module]
> > > > [  407.934248] Code: Unable to access opcode bytes at RIP 0xffffffffc07e1fda.
> > > > [  407.934249] RSP: 0018:ffffb21440487c20 EFLAGS: 00010202
> > > > [  407.934251] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> > > > [  407.934252] RDX: 0000000000000000 RSI: ffffffff9c38e5e1 RDI: 0000000000000001
> > > > [  407.934253] RBP: ffffb21440487c28 R08: 0000000000000000 R09: ffffb21440487a20
> > > > [  407.934254] R10: ffffb21440487a18 R11: ffffffff9c755248 R12: ffffffffc07ee007
> > > > [  407.934255] R13: ffff92a0f1e260b0 R14: 0000000000000000 R15: 0000000000000000
> > > > [  407.934256] FS:  00007f578ebc4400(0000) GS:ffff92a1c0e00000(0000) knlGS:0000000000000000
> > > > [  407.934257] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > > > [  407.934258] CR2: ffffffffc07e1fda CR3: 00000000063ea006 CR4: 00000000000706f0
> > > > [  407.934260] Call Trace:
> > > > [  407.934260]  <TASK>
> > > > [  407.934261]  ? init_module+0x5a/0xff9 [test_module]
> > > >
> > > > note that it is able to decode RIP to an offset from module start or
> > > > init start now.
> > > >
> > > > tested on linux->next (tag next-20211220)
> > > >
> > > > Signed-off-by: Vimal Agrawal <vimal.agrawal@sophos.com>
> > > > Acked-by: Nishit Shah <nishit.shah@sophos.com>
> > > > Suggested-by: Dirk VanDerMerwe <Dirk.VanDerMerwe@Sophos.com>
> > > > ---
> > > >  kernel/module.c | 44 +++++++++++++++++++++++++++++++++++++++-----
> > > >  1 file changed, 39 insertions(+), 5 deletions(-)
> > > >
> > > > diff --git a/kernel/module.c b/kernel/module.c
> > > > index 24dab046e16c..635e631c92f1 100644
> > > > --- a/kernel/module.c
> > > > +++ b/kernel/module.c
> > > > @@ -4260,6 +4260,19 @@ static const char *kallsyms_symbol_name(struct mod_kallsyms *kallsyms, unsigned
> > > >       return kallsyms->strtab + kallsyms->symtab[symnum].st_name;
> > > >  }
> > > >
> > > > +/*
> > > > + * Check if module address (addr) passed is as per init passed
> > > > + * if init is true then check in init layout
> > > > + * else check in core layout
> > > > + */
> > > > +bool match_address_layout(struct module *mod, unsigned long addr, bool init)
> > > > +{
> > > > +     if (init)
> > > > +             return within_module_init(addr, mod);
> > > > +     else
> > > > +             return within_module_core(addr, mod);
> > > > +}
> > > > +
> > > >  /*
> > > >   * Given a module and address, find the corresponding symbol and return its name
> > > >   * while providing its size and offset if needed.
> > > > @@ -4270,14 +4283,22 @@ static const char *find_kallsyms_symbol(struct module *mod,
> > > >                                       unsigned long *offset)
> > > >  {
> > > >       unsigned int i, best = 0;
> > > > -     unsigned long nextval, bestval;
> > > > +     unsigned long baseval, nextval, bestval;
> > > >       struct mod_kallsyms *kallsyms = rcu_dereference_sched(mod->kallsyms);
> > > > +     char *module_base_name;
> > > > +     bool is_init_address = false;
> > > >
> > > >       /* At worse, next value is at end of module */
> > > > -     if (within_module_init(addr, mod))
> > > > +     if (within_module_init(addr, mod)) {
> > > > +             baseval = (unsigned long)mod->init_layout.base;
> > > >               nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
> > > > -     else
> > > > +             module_base_name = "[module __init]";
> > > > +             is_init_address = true;
> > > > +     } else {
> > > > +             baseval = (unsigned long)mod->core_layout.base;
> > > >               nextval = (unsigned long)mod->core_layout.base+mod->core_layout.text_size;
> > > > +             module_base_name = "[module]";
> > > > +     }
> > > >
> > >
> > >
> > > To make all this readible and easier to follow please break down your
> > > work into 3 patches:
> > >
> > > 1) You add the above branch and add baseval as you do now and you also
> > > use it on the nextval assigmment. So something like this:
> > >
> > > +             baseval = (unsigned long)mod->init_layout.base;
> > > -             nextval = (unsigned long)mod->init_layout.base+mod->init_layout.text_size;
> > > +             nextval = baseval + mod->init_layout.text_size;
> > >
> > > You would do that for the core_layout branch too.
> > >
> > > This would make only one single change to the code. That is just one
> > > patch. And that patch introduces no functional changes. You would
> > > clarify that on the commit log, to make it clear there is no possible
> > > regression risks with it.
> > >
> > > >       bestval = kallsyms_symbol_value(&kallsyms->symtab[best]);
> > > >
> > > > @@ -4300,7 +4321,8 @@ static const char *find_kallsyms_symbol(struct module *mod,
> > > >                   || is_arm_mapping_symbol(kallsyms_symbol_name(kallsyms, i)))
> > > >                       continue;
> > > >
> > > > -             if (thisval <= addr && thisval > bestval) {
> > > > +             if ((thisval <= addr && thisval > bestval) &&
> > > > +                     (match_address_layout(mod, thisval, is_init_address))) {
> > >
> > > OK your 2nd patch will be:
> > >
> > > 2) You add match_address_layout() and the is_init_address bool. This is
> > > a fix found through code inspection. You can clarify that the issue has
> > > only been found when --strip-unneeded is used, however, that the fix
> > > could potentialy solve other false symbol. At this point in time no
> > > known cases are known where the reported symbol returned is invalid,
> > > but this sanity check makes sense even for cases where no striping is
> > > used. You can also mention that you this fix is also being added to
> > > be able to add a new heuristic later for cases where --strip-unneeded
> > > is used.
> > >
> > > >                       best = i;
> > > >                       bestval = thisval;
> > > >               }
> > > > @@ -4308,8 +4330,20 @@ static const char *find_kallsyms_symbol(struct module *mod,
> > > >                       nextval = thisval;
> > > >       }
> > > >
> > > > -     if (!best)
> > > > +     if (!best) {
> > > > +             if (is_module_text_address(addr)) {
> > > > +                     /*
> > > > +                      * return MODULE base and offset if we could not find
> > > > +                      * any best match for text address
> > > > +                      */
> > > > +                     if (size)
> > > > +                             *size = nextval - baseval;
> > > > +                     if (offset)
> > > > +                             *offset = addr - baseval;
> > > > +                     return module_base_name;
> > > > +             }
> > > >               return NULL;
> > >
> > > And then patch 3 is this new change. Please test the config I sent you
> > > though, I have not been able to reproduce your setup yet.
> > >
> > >   Luis
> > sure I will do as suggested. Thanks.
> >
> > Vimal

^ permalink raw reply	[flat|nested] 36+ messages in thread

end of thread, other threads:[~2022-02-25 13:40 UTC | newest]

Thread overview: 36+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
     [not found] <LO2P265MB2671DF8D82C0C6A1504D85D6939F9@LO2P265MB2671.GBRP265.PROD.OUTLOOK.COM>
     [not found] ` <LO2P265MB267173F563B0A2CA5995FA2C939F9@LO2P265MB2671.GBRP265.PROD.OUTLOOK.COM>
2021-11-22 14:02   ` [PATCH] kernel/module.c: fix for symbol decode in stack trace for stripped modules Vimal Agrawal
2021-12-08 19:33     ` Luis Chamberlain
2021-12-09  5:37       ` Vimal Agrawal
2021-12-09 20:40         ` Luis Chamberlain
2021-12-20  8:57           ` Vimal Agrawal
2021-12-20 19:21             ` Luis Chamberlain
2021-12-21  9:06               ` Vimal Agrawal
2021-12-21 17:16                 ` Vimal Agrawal
2021-12-21 22:45                   ` Luis Chamberlain
2021-12-21 22:46                 ` Luis Chamberlain
2021-12-22 13:23                   ` [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used Vimal Agrawal
2021-12-23 10:36                     ` Christoph Hellwig
2021-12-23 11:09                       ` Vimal Agrawal
2021-12-24  6:47                         ` Christoph Hellwig
2021-12-25  1:08                           ` Vimal Agrawal
2022-01-11 15:49                             ` Luis Chamberlain
2022-01-12  8:36                               ` Vimal Agrawal
2022-01-13 15:23                                 ` Luis Chamberlain
2022-01-17  6:54                                   ` [PATCH v3] kernel/module.c: heuristic enhancement in case symbols are missing e.g. " Vimal Agrawal
2022-02-02 20:20                                     ` Luis Chamberlain
2022-02-03  5:54                                       ` Vimal Agrawal
2022-02-03  6:06                                       ` [PATCH v4] modules: add heuristic when stripping unneeded symbols Vimal Agrawal
2022-02-04  8:39                                         ` [PATCH v5] " Vimal Agrawal
2022-02-04 21:47                                           ` Luis Chamberlain
2022-02-07 13:21                                             ` Vimal Agrawal
2022-02-07 22:07                                               ` Luis Chamberlain
2022-02-08  4:52                                                 ` Vimal Agrawal
2022-02-08 11:02                                                   ` [PATCH v6] " Vimal Agrawal
2022-02-08 11:13                                                     ` Vimal Agrawal
2022-02-08 18:10                                                     ` Luis Chamberlain
2022-02-08 18:25                                                       ` Vimal Agrawal
2022-02-25  7:59                                                         ` Vimal Agrawal
2022-02-25 13:40                                                           ` Vimal Agrawal
2022-02-08 17:55                                                   ` [PATCH v5] " Luis Chamberlain
2022-02-08 18:12                                                     ` Vimal Agrawal
2022-01-17  7:34                                   ` [PATCH v2] kernel/module.c: heuristic enhancement when INSTALL_MOD_STRIP= "--strip-unneeded" is used Vimal Agrawal

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.