[PATCH 0/2] Print out load addresses for .text and .data

[PATCH 0/2] Print out load addresses for .text and .data

[Robbie Harwood]

Hi,

These patches display (in format that can be copy/pasted to gdb) the virtual
addresses of grub-core/kernel.exec (and any modules it loads).

First patch is prep work - adds a print without numbering.  The second patch
is better with this call, since it makes copy/pasting easier.

(These have been downstream for just over six years now.)

Be well,
--Robbie

Peter Jones (2):
  Add grub_qdprintf() - grub_dprintf() without the file+line number.
  Make a "gdb" dprintf that tells us load addresses.

 grub-core/kern/dl.c       | 50 +++++++++++++++++++++++++++++++++++++++
 grub-core/kern/efi/efi.c  |  4 ++--
 grub-core/kern/efi/init.c | 26 +++++++++++++++++++-
 grub-core/kern/misc.c     | 18 ++++++++++++++
 include/grub/efi/efi.h    |  2 +-
 include/grub/misc.h       |  2 ++
 6 files changed, 98 insertions(+), 4 deletions(-)

-- 
2.33.0

[PATCH 1/2] Add grub_qdprintf() - grub_dprintf() without the file+line number.

[Robbie Harwood]

From: Peter Jones <pjones@redhat.com>

This just makes copy+paste of our debug loading info easier.

Signed-off-by: Peter Jones <pjones@redhat.com>
Signed-off-by: Robbie Harwood <rharwood@redhat.com>
---
 grub-core/kern/misc.c | 18 ++++++++++++++++++
 include/grub/misc.h   |  2 ++
 2 files changed, 20 insertions(+)

diff --git a/grub-core/kern/misc.c b/grub-core/kern/misc.c
index 3af336ee2..633fb48ec 100644
--- a/grub-core/kern/misc.c
+++ b/grub-core/kern/misc.c
@@ -190,6 +190,24 @@ grub_real_dprintf (const char *file, const int line, const char *condition,
     }
 }
 
+void
+grub_qdprintf (const char *condition, const char *fmt, ...)
+{
+  va_list args;
+  const char *debug = grub_env_get ("debug");
+
+  if (! debug)
+    return;
+
+  if (grub_strword (debug, "all") || grub_strword (debug, condition))
+    {
+      va_start (args, fmt);
+      grub_vprintf (fmt, args);
+      va_end (args);
+      grub_refresh ();
+    }
+}
+
 #define PREALLOC_SIZE 255
 
 int
diff --git a/include/grub/misc.h b/include/grub/misc.h
index 7d2b55196..b9b22b2ec 100644
--- a/include/grub/misc.h
+++ b/include/grub/misc.h
@@ -345,6 +345,8 @@ void EXPORT_FUNC(grub_real_dprintf) (const char *file,
                                      const int line,
                                      const char *condition,
                                      const char *fmt, ...) __attribute__ ((format (GNU_PRINTF, 4, 5)));
+void EXPORT_FUNC(grub_qdprintf) (const char *condition,
+				 const char *fmt, ...) __attribute__ ((format (GNU_PRINTF, 2, 3)));
 int EXPORT_FUNC(grub_vprintf) (const char *fmt, va_list args);
 int EXPORT_FUNC(grub_snprintf) (char *str, grub_size_t n, const char *fmt, ...)
      __attribute__ ((format (GNU_PRINTF, 3, 4)));
-- 
2.33.0

Re: [PATCH 1/2] Add grub_qdprintf() - grub_dprintf() without the file+line number.

[Glenn Washburn]

On Mon, 11 Oct 2021 14:48:43 -0400
Robbie Harwood <rharwood@redhat.com> wrote:

> From: Peter Jones <pjones@redhat.com>
> 
> This just makes copy+paste of our debug loading info easier.
> 
> Signed-off-by: Peter Jones <pjones@redhat.com>
> Signed-off-by: Robbie Harwood <rharwood@redhat.com>
> ---
>  grub-core/kern/misc.c | 18 ++++++++++++++++++
>  include/grub/misc.h   |  2 ++
>  2 files changed, 20 insertions(+)
> 
> diff --git a/grub-core/kern/misc.c b/grub-core/kern/misc.c
> index 3af336ee2..633fb48ec 100644
> --- a/grub-core/kern/misc.c
> +++ b/grub-core/kern/misc.c
> @@ -190,6 +190,24 @@ grub_real_dprintf (const char *file, const int line, const char *condition,
>      }
>  }
>  
> +void
> +grub_qdprintf (const char *condition, const char *fmt, ...)
> +{
> +  va_list args;
> +  const char *debug = grub_env_get ("debug");
> +
> +  if (! debug)
> +    return;
> +
> +  if (grub_strword (debug, "all") || grub_strword (debug, condition))

Is there a good reason why this is done like this instead of using
grub_debug_enabled as in grub_real_dprintf.

> +    {
> +      va_start (args, fmt);
> +      grub_vprintf (fmt, args);
> +      va_end (args);
> +      grub_refresh ();
> +    }

I don't particularly like, that this function is mostly a copy of
grub_real_dprintf. What about modifying grub_real_dprintf to not print
the file:line if file == NULL? Then have grub_qdprintf be a macro to
grub_real_dprintf as grub_dprintf is. This would obviate the concern
above.

> +}
> +
>  #define PREALLOC_SIZE 255
>  
>  int
> diff --git a/include/grub/misc.h b/include/grub/misc.h
> index 7d2b55196..b9b22b2ec 100644
> --- a/include/grub/misc.h
> +++ b/include/grub/misc.h
> @@ -345,6 +345,8 @@ void EXPORT_FUNC(grub_real_dprintf) (const char *file,
>                                       const int line,
>                                       const char *condition,
>                                       const char *fmt, ...) __attribute__ ((format (GNU_PRINTF, 4, 5)));
> +void EXPORT_FUNC(grub_qdprintf) (const char *condition,
> +				 const char *fmt, ...) __attribute__ ((format (GNU_PRINTF, 2, 3)));
>  int EXPORT_FUNC(grub_vprintf) (const char *fmt, va_list args);
>  int EXPORT_FUNC(grub_snprintf) (char *str, grub_size_t n, const char *fmt, ...)
>       __attribute__ ((format (GNU_PRINTF, 3, 4)));

Glenn

[PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Robbie Harwood]

From: Peter Jones <pjones@redhat.com>

This makes a grub_dprintf() call during platform init and during module
loading that tells us the virtual addresses of the .text and .data
sections of grub-core/kernel.exec and any modules it loads.

Specifically, it displays them in the gdb "add-symbol-file" syntax, with
the presumption that there's a variable $grubdir that reflects the path
to any such binaries.

Signed-off-by: Peter Jones <pjones@redhat.com>
Signed-off-by: Robbie Harwood <rharwood@redhat.com>
---
 grub-core/kern/dl.c       | 50 +++++++++++++++++++++++++++++++++++++++
 grub-core/kern/efi/efi.c  |  4 ++--
 grub-core/kern/efi/init.c | 26 +++++++++++++++++++-
 include/grub/efi/efi.h    |  2 +-
 4 files changed, 78 insertions(+), 4 deletions(-)

diff --git a/grub-core/kern/dl.c b/grub-core/kern/dl.c
index 48f8a7907..44a1f4ca3 100644
--- a/grub-core/kern/dl.c
+++ b/grub-core/kern/dl.c
@@ -447,6 +447,23 @@ grub_dl_find_section (Elf_Ehdr *e, const char *name)
       return s;
   return NULL;
 }
+static long
+grub_dl_find_section_index (Elf_Ehdr *e, const char *name)
+{
+  Elf_Shdr *s;
+  const char *str;
+  unsigned i;
+
+  s = (Elf_Shdr *) ((char *) e + e->e_shoff + e->e_shstrndx * e->e_shentsize);
+  str = (char *) e + s->sh_offset;
+
+  for (i = 0, s = (Elf_Shdr *) ((char *) e + e->e_shoff);
+       i < e->e_shnum;
+       i++, s = (Elf_Shdr *) ((char *) s + e->e_shentsize))
+    if (grub_strcmp (str + s->sh_name, name) == 0)
+      return (long)i;
+  return -1;
+}
 
 /* Me, Vladimir Serbinenko, hereby I add this module check as per new
    GNU module policy. Note that this license check is informative only.
@@ -599,6 +616,37 @@ grub_dl_relocate_symbols (grub_dl_t mod, void *ehdr)
 
   return GRUB_ERR_NONE;
 }
+static void
+grub_dl_print_gdb_info (grub_dl_t mod, Elf_Ehdr *e)
+{
+  void *text, *data = NULL;
+  long idx;
+
+  idx = grub_dl_find_section_index (e, ".text");
+  if (idx < 0)
+    return;
+
+  text = grub_dl_get_section_addr (mod, idx);
+  if (!text)
+    return;
+
+  idx = grub_dl_find_section_index (e, ".data");
+  if (idx >= 0)
+    data = grub_dl_get_section_addr (mod, idx);
+
+  if (data)
+    grub_qdprintf ("gdb", "add-symbol-file \\\n"
+		          "/usr/lib/debug/usr/lib/grub/%s-%s/%s.debug "
+			  "\\\n %p -s .data %p\n",
+		  GRUB_TARGET_CPU, GRUB_PLATFORM,
+		  mod->name, text, data);
+  else
+    grub_qdprintf ("gdb", "add-symbol-file \\\n"
+			   "/usr/lib/debug/usr/lib/grub/%s-%s/%s.debug "
+			   "\\\n%p\n",
+		  GRUB_TARGET_CPU, GRUB_PLATFORM,
+		  mod->name, text);
+}
 
 /* Load a module from core memory.  */
 grub_dl_t
@@ -658,6 +706,8 @@ grub_dl_load_core_noinit (void *addr, grub_size_t size)
   grub_dprintf ("modules", "module name: %s\n", mod->name);
   grub_dprintf ("modules", "init function: %p\n", mod->init);
 
+  grub_dl_print_gdb_info (mod, e);
+
   if (grub_dl_add (mod))
     {
       grub_dl_unload (mod);
diff --git a/grub-core/kern/efi/efi.c b/grub-core/kern/efi/efi.c
index 8cff7be02..f12fd5893 100644
--- a/grub-core/kern/efi/efi.c
+++ b/grub-core/kern/efi/efi.c
@@ -291,7 +291,7 @@ grub_efi_get_variable (const char *var, const grub_efi_guid_t *guid,
 /* Search the mods section from the PE32/PE32+ image. This code uses
    a PE32 header, but should work with PE32+ as well.  */
 grub_addr_t
-grub_efi_modules_addr (void)
+grub_efi_section_addr (const char *section_name)
 {
   grub_efi_loaded_image_t *image;
   struct grub_pe32_header *header;
@@ -316,7 +316,7 @@ grub_efi_modules_addr (void)
        i < coff_header->num_sections;
        i++, section++)
     {
-      if (grub_strcmp (section->name, "mods") == 0)
+      if (grub_strcmp (section->name, section_name) == 0)
 	break;
     }
 
diff --git a/grub-core/kern/efi/init.c b/grub-core/kern/efi/init.c
index 7facacf09..da7be3b12 100644
--- a/grub-core/kern/efi/init.c
+++ b/grub-core/kern/efi/init.c
@@ -82,10 +82,33 @@ stack_protector_init (void)
 
 grub_addr_t grub_modbase;
 
+static void
+grub_efi_print_gdb_info (void)
+{
+  grub_addr_t text;
+  grub_addr_t data;
+
+  text = grub_efi_section_addr (".text");
+  if (!text)
+    return;
+
+  data = grub_efi_section_addr (".data");
+  if (data)
+    grub_qdprintf ("gdb",
+		  "add-symbol-file /usr/lib/debug/usr/lib/grub/%s-%s/"
+		  "kernel.exec %p -s .data %p\n",
+		  GRUB_TARGET_CPU, GRUB_PLATFORM, (void *)text, (void *)data);
+  else
+    grub_qdprintf ("gdb",
+		  "add-symbol-file /usr/lib/debug/usr/lib/grub/%s-%s/"
+		  "kernel.exec %p\n",
+		  GRUB_TARGET_CPU, GRUB_PLATFORM, (void *)text);
+}
+
 void
 grub_efi_init (void)
 {
-  grub_modbase = grub_efi_modules_addr ();
+  grub_modbase = grub_efi_section_addr ("mods");
   /* First of all, initialize the console so that GRUB can display
      messages.  */
   grub_console_init ();
@@ -108,6 +131,7 @@ grub_efi_init (void)
   efi_call_4 (grub_efi_system_table->boot_services->set_watchdog_timer,
 	      0, 0, 0, NULL);
 
+  grub_efi_print_gdb_info ();
   grub_efidisk_init ();
 }
 
diff --git a/include/grub/efi/efi.h b/include/grub/efi/efi.h
index 83d958f99..73b754177 100644
--- a/include/grub/efi/efi.h
+++ b/include/grub/efi/efi.h
@@ -105,7 +105,7 @@ grub_err_t grub_arch_efi_linux_boot_image(grub_addr_t addr, grub_size_t size,
                                            char *args);
 #endif
 
-grub_addr_t grub_efi_modules_addr (void);
+grub_addr_t grub_efi_section_addr (const char *section);
 
 void grub_efi_mm_init (void);
 void grub_efi_mm_fini (void);
-- 
2.33.0

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Glenn Washburn]

On Mon, 11 Oct 2021 14:48:44 -0400
Robbie Harwood <rharwood@redhat.com> wrote:

> From: Peter Jones <pjones@redhat.com>
> 
> This makes a grub_dprintf() call during platform init and during module
> loading that tells us the virtual addresses of the .text and .data
> sections of grub-core/kernel.exec and any modules it loads.
> 
> Specifically, it displays them in the gdb "add-symbol-file" syntax, with
> the presumption that there's a variable $grubdir that reflects the path
> to any such binaries.
> 
> Signed-off-by: Peter Jones <pjones@redhat.com>
> Signed-off-by: Robbie Harwood <rharwood@redhat.com>
> ---
>  grub-core/kern/dl.c       | 50 +++++++++++++++++++++++++++++++++++++++
>  grub-core/kern/efi/efi.c  |  4 ++--
>  grub-core/kern/efi/init.c | 26 +++++++++++++++++++-
>  include/grub/efi/efi.h    |  2 +-
>  4 files changed, 78 insertions(+), 4 deletions(-)
> 
> diff --git a/grub-core/kern/dl.c b/grub-core/kern/dl.c
> index 48f8a7907..44a1f4ca3 100644
> --- a/grub-core/kern/dl.c
> +++ b/grub-core/kern/dl.c
> @@ -447,6 +447,23 @@ grub_dl_find_section (Elf_Ehdr *e, const char *name)
>        return s;
>    return NULL;
>  }
> +static long
> +grub_dl_find_section_index (Elf_Ehdr *e, const char *name)
> +{
> +  Elf_Shdr *s;
> +  const char *str;
> +  unsigned i;
> +
> +  s = (Elf_Shdr *) ((char *) e + e->e_shoff + e->e_shstrndx * e->e_shentsize);
> +  str = (char *) e + s->sh_offset;
> +
> +  for (i = 0, s = (Elf_Shdr *) ((char *) e + e->e_shoff);
> +       i < e->e_shnum;
> +       i++, s = (Elf_Shdr *) ((char *) s + e->e_shentsize))
> +    if (grub_strcmp (str + s->sh_name, name) == 0)
> +      return (long)i;
> +  return -1;
> +}
>  
>  /* Me, Vladimir Serbinenko, hereby I add this module check as per new
>     GNU module policy. Note that this license check is informative only.
> @@ -599,6 +616,37 @@ grub_dl_relocate_symbols (grub_dl_t mod, void *ehdr)
>  
>    return GRUB_ERR_NONE;
>  }
> +static void
> +grub_dl_print_gdb_info (grub_dl_t mod, Elf_Ehdr *e)
> +{
> +  void *text, *data = NULL;
> +  long idx;
> +
> +  idx = grub_dl_find_section_index (e, ".text");
> +  if (idx < 0)
> +    return;
> +
> +  text = grub_dl_get_section_addr (mod, idx);
> +  if (!text)
> +    return;
> +
> +  idx = grub_dl_find_section_index (e, ".data");
> +  if (idx >= 0)
> +    data = grub_dl_get_section_addr (mod, idx);
> +
> +  if (data)
> +    grub_qdprintf ("gdb", "add-symbol-file \\\n"
> +		          "/usr/lib/debug/usr/lib/grub/%s-%s/%s.debug "
> +			  "\\\n %p -s .data %p\n",
> +		  GRUB_TARGET_CPU, GRUB_PLATFORM,
> +		  mod->name, text, data);
> +  else
> +    grub_qdprintf ("gdb", "add-symbol-file \\\n"
> +			   "/usr/lib/debug/usr/lib/grub/%s-%s/%s.debug "
> +			   "\\\n%p\n",
> +		  GRUB_TARGET_CPU, GRUB_PLATFORM,
> +		  mod->name, text);
> +}

I don't agree with suppressing file:line for debug output. I have some
changes in the pipeline which will allow selectively disabling
conditions when also using "deubg=all". Suppressing file:line makes it
harder to figure out where the debug output is coming from to find the
condition to disable it. I think solution that we both might find agree
able is to prepend "\n" to your format string. That way
"add-symbol-file" will still start on a new-line, which seems to be
what you're after.

>  
>  /* Load a module from core memory.  */
>  grub_dl_t
> @@ -658,6 +706,8 @@ grub_dl_load_core_noinit (void *addr, grub_size_t size)
>    grub_dprintf ("modules", "module name: %s\n", mod->name);
>    grub_dprintf ("modules", "init function: %p\n", mod->init);
>  
> +  grub_dl_print_gdb_info (mod, e);
> +
>    if (grub_dl_add (mod))
>      {
>        grub_dl_unload (mod);
> diff --git a/grub-core/kern/efi/efi.c b/grub-core/kern/efi/efi.c
> index 8cff7be02..f12fd5893 100644
> --- a/grub-core/kern/efi/efi.c
> +++ b/grub-core/kern/efi/efi.c
> @@ -291,7 +291,7 @@ grub_efi_get_variable (const char *var, const grub_efi_guid_t *guid,
>  /* Search the mods section from the PE32/PE32+ image. This code uses
>     a PE32 header, but should work with PE32+ as well.  */
>  grub_addr_t
> -grub_efi_modules_addr (void)
> +grub_efi_section_addr (const char *section_name)
>  {
>    grub_efi_loaded_image_t *image;
>    struct grub_pe32_header *header;
> @@ -316,7 +316,7 @@ grub_efi_modules_addr (void)
>         i < coff_header->num_sections;
>         i++, section++)
>      {
> -      if (grub_strcmp (section->name, "mods") == 0)
> +      if (grub_strcmp (section->name, section_name) == 0)
>  	break;
>      }
>  
> diff --git a/grub-core/kern/efi/init.c b/grub-core/kern/efi/init.c
> index 7facacf09..da7be3b12 100644
> --- a/grub-core/kern/efi/init.c
> +++ b/grub-core/kern/efi/init.c
> @@ -82,10 +82,33 @@ stack_protector_init (void)
>  
>  grub_addr_t grub_modbase;
>  
> +static void
> +grub_efi_print_gdb_info (void)
> +{
> +  grub_addr_t text;
> +  grub_addr_t data;
> +
> +  text = grub_efi_section_addr (".text");
> +  if (!text)
> +    return;
> +
> +  data = grub_efi_section_addr (".data");
> +  if (data)
> +    grub_qdprintf ("gdb",
> +		  "add-symbol-file /usr/lib/debug/usr/lib/grub/%s-%s/"
> +		  "kernel.exec %p -s .data %p\n",
> +		  GRUB_TARGET_CPU, GRUB_PLATFORM, (void *)text, (void *)data);
> +  else
> +    grub_qdprintf ("gdb",
> +		  "add-symbol-file /usr/lib/debug/usr/lib/grub/%s-%s/"
> +		  "kernel.exec %p\n",
> +		  GRUB_TARGET_CPU, GRUB_PLATFORM, (void *)text);
> +}
> +

ditto.

>  void
>  grub_efi_init (void)
>  {
> -  grub_modbase = grub_efi_modules_addr ();
> +  grub_modbase = grub_efi_section_addr ("mods");
>    /* First of all, initialize the console so that GRUB can display
>       messages.  */
>    grub_console_init ();
> @@ -108,6 +131,7 @@ grub_efi_init (void)
>    efi_call_4 (grub_efi_system_table->boot_services->set_watchdog_timer,
>  	      0, 0, 0, NULL);
>  
> +  grub_efi_print_gdb_info ();
>    grub_efidisk_init ();
>  }
>  
> diff --git a/include/grub/efi/efi.h b/include/grub/efi/efi.h
> index 83d958f99..73b754177 100644
> --- a/include/grub/efi/efi.h
> +++ b/include/grub/efi/efi.h
> @@ -105,7 +105,7 @@ grub_err_t grub_arch_efi_linux_boot_image(grub_addr_t addr, grub_size_t size,
>                                             char *args);
>  #endif
>  
> -grub_addr_t grub_efi_modules_addr (void);
> +grub_addr_t grub_efi_section_addr (const char *section);
>  
>  void grub_efi_mm_init (void);
>  void grub_efi_mm_fini (void);

Glenn

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Robbie Harwood]

[-- Attachment #1: Type: text/plain, Size: 887 bytes --]

Glenn Washburn <development@efficientek.com> writes:

> I don't agree with suppressing file:line for debug output. I have some
> changes in the pipeline which will allow selectively disabling
> conditions when also using "deubg=all". Suppressing file:line makes it
> harder to figure out where the debug output is coming from to find the
> condition to disable it.

Grep for add-symbol-file or /usr/lib/debug etc. will get there.  

> I think solution that we both might find agree able is to prepend "\n"
> to your format string. That way "add-symbol-file" will still start on
> a new-line, which seems to be what you're after.

During a boot with this enabled, you don't get just one line - you get
one for each module (plus the initial one for kernel.exec).  So if
nothing intersperses, you can do `set confirm off`, then copy/paste the
block.

Be well,
--Robbie

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 861 bytes --]

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Glenn Washburn]

On Thu, 14 Oct 2021 13:09:21 -0400
Robbie Harwood <rharwood@redhat.com> wrote:

> Glenn Washburn <development@efficientek.com> writes:
> 
> > I don't agree with suppressing file:line for debug output. I have some
> > changes in the pipeline which will allow selectively disabling
> > conditions when also using "debug=all". Suppressing file:line makes it
> > harder to figure out where the debug output is coming from to find the
> > condition to disable it.
> 
> Grep for add-symbol-file or /usr/lib/debug etc. will get there.

I'm not following. Are you suggesting grepping for "add-symbol-file" in
the source? If so, I don't find that an acceptable answer to the
sysadmin trying to figure out hwo to disable that log message.

> > I think solution that we both might find agree able is to prepend "\n"
> > to your format string. That way "add-symbol-file" will still start on
> > a new-line, which seems to be what you're after.
> 
> During a boot with this enabled, you don't get just one line - you get
> one for each module (plus the initial one for kernel.exec).  So if
> nothing intersperses, you can do `set confirm off`, then copy/paste the
> block.

Yes I understood this is per module, and I'm also confused here as to
why this is your response because it doesn't address what its supposedly
responding to. You're just talking about how to use the functionality
that this patch provides. With the change that I suggest the actions in
your response would be the same.

> Be well,
> --Robbie

Glenn

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Robbie Harwood]

[-- Attachment #1: Type: text/plain, Size: 975 bytes --]

Glenn Washburn <development@efficientek.com> writes:

> Robbie Harwood <rharwood@redhat.com> wrote:
>> Glenn Washburn <development@efficientek.com> writes:
>> 
>>> I don't agree with suppressing file:line for debug output. I have
>>> some changes in the pipeline which will allow selectively disabling
>>> conditions when also using "debug=all". Suppressing file:line makes
>>> it harder to figure out where the debug output is coming from to
>>> find the condition to disable it.
>> 
>> Grep for add-symbol-file or /usr/lib/debug etc. will get there.
>
> I'm not following. Are you suggesting grepping for "add-symbol-file"
> in the source? If so, I don't find that an acceptable answer to the
> sysadmin trying to figure out hwo to disable that log message.

I don't understand your target audience - they have access to the
source, but can't search it?  Do I have that right?

If so, it seems unlikely that we're going to agree.

Be well,
--Robbie

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 861 bytes --]

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Glenn Washburn]

On Fri, 15 Oct 2021 16:55:17 -0400
Robbie Harwood <rharwood@redhat.com> wrote:

> Glenn Washburn <development@efficientek.com> writes:
> 
> > Robbie Harwood <rharwood@redhat.com> wrote:
> >> Glenn Washburn <development@efficientek.com> writes:
> >> 
> >>> I don't agree with suppressing file:line for debug output. I have
> >>> some changes in the pipeline which will allow selectively disabling
> >>> conditions when also using "debug=all". Suppressing file:line makes
> >>> it harder to figure out where the debug output is coming from to
> >>> find the condition to disable it.
> >> 
> >> Grep for add-symbol-file or /usr/lib/debug etc. will get there.
> >
> > I'm not following. Are you suggesting grepping for "add-symbol-file"
> > in the source? If so, I don't find that an acceptable answer to the
> > sysadmin trying to figure out hwo to disable that log message.
> 
> I don't understand your target audience - they have access to the
> source, but can't search it?  Do I have that right?

No, my target audience is a sysadmin trying to debug why grub is
failing in some way. They might not even be a programmer. But they can
read documentation and make intuitive guesses, but they likely don't
know how to use gdb. Say they are trying to debug an issue, but they
don't know exactly where things are going wrong, but it is reproducible.
This is on a system where all they have is a keyboard and a monitor.
So when the output scrolls off the top of the screen its gone.

They turn on debug=all because they don't know in what conditional(s)
would give them useful debug information. This will spew a lot of debug
messages to the screen, including the messages output by this patch.
The sysadmin may not see anything of value in the output, but will see
lots of messages of no apparent value. It would be nice to using this
output to be able to selectively disable it at runtime.

I forgot to mention that I have another patch that adds the conditional
used to the message to file:line:conditional is prepended. That
combined with a patch that allows selective disabling of debug log
message by conditional, allows the user to iteratively pare down debug
log messages so that the ones of value have a greater likelihood of
being on the limited screen realestate. This would look like, for
example:

  set debug=all,-gdb,-disk,-lexer,-alloc

Now the patch as is does not show the file:line prefix, and wouldn't
show the conditional after my patch. So the user has no way of knowing
what conditional should be used to disable the gdb output. And may
actually be confused because all debug messages are currently prefixed
the file:line, even multiline messages. So the user may thing that the
gdb message is a multiline message that comes from the debug log
message that preceeded it, leading them to disable potentially the
wrong conditional.

So, no, I think it should remain the standard that log messages enabled
via the debug variable always have a file:line prefix.

On the otherhand, since you're able to copy paste, I'm guessing you're
on a serial line or VM and not on in the situation I'm describing. In
which case, without the proposed "\n" modification, having the file:line
prefix is an extremely minor inconvenience (you'll have to find the
start of the add-symbol-file, which won't be at the beginning of the
line). And you can copy-paste, you likely can search that output
anyway. The person in the scenario I describe doesn't have that luxury.

Why do I care? I've been that guy trying to figure out a boot issue
with too much noise in the debug log messages pushing the messages I
needed to see off the screen (and the source wasn't readily available).
And no pager is not always an option if you have hundreds of pages of
log messages to scroll through, it takes forever.

> If so, it seems unlikely that we're going to agree.

I don't think we need to agree (that is for you to agree that the issue
I'm describing is something to be concerned about). However, like I
said, I think we can both be satisfied by not leaving out the file:line
and to prepend "\n" to "add-symbol-file" so that it will start on a new
line. So I'll ask again. Is my proposal an acceptable modification for
the need that you have?

> Be well,
> --Robbie

Cheers,
Glenn

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Robbie Harwood]

[-- Attachment #1: Type: text/plain, Size: 978 bytes --]

Glenn Washburn <development@efficientek.com> writes:

> I don't think we need to agree (that is for you to agree that the issue
> I'm describing is something to be concerned about). However, like I
> said, I think we can both be satisfied by not leaving out the file:line
> and to prepend "\n" to "add-symbol-file" so that it will start on a new
> line. So I'll ask again. Is my proposal an acceptable modification for
> the need that you have?

No, this is what I was trying to explain.  There's one add-symbol-file
line per module.  If there's no file:line, you get something like this:

    add-symbol-file ...
    add-symbol-file ...
    add-symbol-file ...

This can be directly pasted into gdb.

Your proposal results in something like:

    dl.c:694:
    add-symbol-file ...
    dl.c:694:
    add-symbol-file ...
    dl.c:694:
    add-symbol-file ...

You can't easily copy-paste that into gdb.  It needs to be processed to
remove the file:line stuff.

Be well,
--Robbie

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 861 bytes --]

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Glenn Washburn]

On Tue, 19 Oct 2021 17:08:59 -0400
Robbie Harwood <rharwood@redhat.com> wrote:

> Glenn Washburn <development@efficientek.com> writes:
> 
> > I don't think we need to agree (that is for you to agree that the issue
> > I'm describing is something to be concerned about). However, like I
> > said, I think we can both be satisfied by not leaving out the file:line
> > and to prepend "\n" to "add-symbol-file" so that it will start on a new
> > line. So I'll ask again. Is my proposal an acceptable modification for
> > the need that you have?
> 
> No, this is what I was trying to explain.  There's one add-symbol-file
> line per module.  If there's no file:line, you get something like this:
> 
>     add-symbol-file ...
>     add-symbol-file ...
>     add-symbol-file ...
> 
> This can be directly pasted into gdb.

Thank you for clarifying that for me. Technically the patch prints a
multiline debug message, so you don't get one line per module. However,
I see that doesn't matter for your use case because the line
continuation makes it appear as one line in gdb.

> 
> Your proposal results in something like:
> 
>     dl.c:694:
>     add-symbol-file ...
>     dl.c:694:
>     add-symbol-file ...
>     dl.c:694:
>     add-symbol-file ...
> 
> You can't easily copy-paste that into gdb.  It needs to be processed to
> remove the file:line stuff.

Ok, I see now why removing the prefix is important for you. And my
objection still stands. At worst just copy into a file and run grep -v
or sed. There have been alternatives proposed on this thread which may
be preferable.

Glenn

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Thomas Schmitt]

Hi,

Robbie Harwood wrote:
>     dl.c:694:
>     add-symbol-file ...
>     dl.c:694:
>     add-symbol-file ...
>     dl.c:694:
>     add-symbol-file ...
>
> You can't easily copy-paste that into gdb.  It needs to be processed to
> remove the file:line stuff.

How about hiding the "dl.c" lines behind a "#" ?

    # dl.c:694:
    add-symbol-file ...

I don't find the current gdb documentation online from GNU, but
  https://sourceware.org/gdb/current/onlinedocs/gdb/Command-Syntax.html#Command-Syntax
looks young and promises
  "Any text from a # to the end of the line is a comment; it does nothing."
(All gdbs i ever saw fulfill this promise.)


Have a nice day :)

Thomas

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Michael Schierl]

Glenn Washburn <development@efficientek.com> writes:
> Robbie Harwood <rharwood@redhat.com> wrote:
>
> They turn on debug=all because they don't know in what conditional(s)
> would give them useful debug information. This will spew a lot of debug
> messages to the screen, including the messages output by this patch.

BTDT.

> message by conditional, allows the user to iteratively pare down debug
> log messages so that the ones of value have a greater likelihood of
> being on the limited screen realestate. This would look like, for
> example:
>
>   set debug=all,-gdb,-disk,-lexer,-alloc

I would second that.

> Now the patch as is does not show the file:line prefix, and wouldn't
> show the conditional after my patch. So the user has no way of knowing
> what conditional should be used to disable the gdb output.

In fact, is there even a sensible scenario where having these messages
included when debug=all is set? I generally use debug=all to get some
first idea about which driver/device may be causing the boot failure,
and module load addresses will never help with that.

Maybe do not trigger this message on debug=all, or use a completely
different environment variable?

I am also unaware how exactly to debug grub in gdb on various platforms,
do you need special build flags for it? If yes, this functionality could
be limited to that build flags. Especially since if I did not miss
anything, this patch only provides value for efi platform (in an obscure
edge case, from my point of view), yet increases core image size for all
platforms.

> On the otherhand, since you're able to copy paste, I'm guessing you're
> on a serial line or VM and not on in the situation I'm describing. In
> which case, without the proposed "\n" modification, having the file:line
> prefix is an extremely minor inconvenience (you'll have to find the
> start of the add-symbol-file, which won't be at the beginning of the
> line). And you can copy-paste, you likely can search that output
> anyway.

I presume that typical GRUB loads will load dozens of modules, resulting
in dozens of debug outputs, which may often end up on adjacent lines. In
case of a line prefix, you would need to use sed (or some block editor
features) to get rid of the prefixes. In case of a newline after the
debug message, one would need to use grep (or remove every second line
from the output).

> Why do I care? I've been that guy trying to figure out a boot issue
> with too much noise in the debug log messages pushing the messages I
> needed to see off the screen (and the source wasn't readily available).
> And no pager is not always an option if you have hundreds of pages of
> log messages to scroll through, it takes forever.

As I have been in the same situation before, too, I second that. I would
also like a feature so that debug messages (or all output) get spewn
into a file (overwriting existing bytes similar to how grub_env works,
acting like a ring buffer on the file). So you could boot some recovery
envionment to create a sufficiently large file, set debug=all, let debug
logs write into that file, and then analyze them after another reboot
into said environment. Or when GRUB is booted from a USB key, the file
can be created/analyzed on another machine.

This may not help if nothing boots on that machine, but in my experience
there is either some non-Linux operating system already installed on
that machine that fails to boot Linux from GRUB, or at least a recovery
environment from another OS can be booted.

> I don't think we need to agree (that is for you to agree that the issue
> I'm describing is something to be concerned about). However, like I
> said, I think we can both be satisfied by not leaving out the file:line
> and to prepend "\n" to "add-symbol-file" so that it will start on a new
> line. So I'll ask again. Is my proposal an acceptable modification for
> the need that you have?

Another way (if possible, I don't know GRUB internals enough) would be
to provide a module similar to lsmod that shows this output for all
loaded modules. Users could load it if they want to use gdb and invoke
it during their debug session. Then copy&paste the output in one single
block.


Regards,


Michael

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Glenn Washburn]

On Sat, 16 Oct 2021 19:48:45 +0200
Michael Schierl <schierlm@gmx.de> wrote:

> Glenn Washburn <development@efficientek.com> writes:
> > Robbie Harwood <rharwood@redhat.com> wrote:
> >
> > They turn on debug=all because they don't know in what conditional(s)
> > would give them useful debug information. This will spew a lot of debug
> > messages to the screen, including the messages output by this patch.
> 
> BTDT.
> 
> > message by conditional, allows the user to iteratively pare down debug
> > log messages so that the ones of value have a greater likelihood of
> > being on the limited screen realestate. This would look like, for
> > example:
> >
> >   set debug=all,-gdb,-disk,-lexer,-alloc
> 
> I would second that.

Great, I'm not the only one. I'll see about submitting that patch
sooner than later then.

> > Now the patch as is does not show the file:line prefix, and wouldn't
> > show the conditional after my patch. So the user has no way of knowing
> > what conditional should be used to disable the gdb output.
> 
> In fact, is there even a sensible scenario where having these messages
> included when debug=all is set? I generally use debug=all to get some
> first idea about which driver/device may be causing the boot failure,
> and module load addresses will never help with that.
> 
> Maybe do not trigger this message on debug=all, or use a completely
> different environment variable?

I can't say I'm a fan of another special variable, but I'd also be fine
with that route. Another route might be a (proc) file, eg. "/gsyms",
which outputs add-symbol-file lines for all loaded modules. This could
be put in its own module, eg. gdb-syms, which would address the
increasing the core image size concern below.

> 
> I am also unaware how exactly to debug grub in gdb on various platforms,
> do you need special build flags for it? If yes, this functionality could
> be limited to that build flags. Especially since if I did not miss
> anything, this patch only provides value for efi platform (in an obscure
> edge case, from my point of view), yet increases core image size for all
> platforms.
> 
> > On the otherhand, since you're able to copy paste, I'm guessing you're
> > on a serial line or VM and not on in the situation I'm describing. In
> > which case, without the proposed "\n" modification, having the file:line
> > prefix is an extremely minor inconvenience (you'll have to find the
> > start of the add-symbol-file, which won't be at the beginning of the
> > line). And you can copy-paste, you likely can search that output
> > anyway.
> 
> I presume that typical GRUB loads will load dozens of modules, resulting
> in dozens of debug outputs, which may often end up on adjacent lines. In
> case of a line prefix, you would need to use sed (or some block editor
> features) to get rid of the prefixes. In case of a newline after the
> debug message, one would need to use grep (or remove every second line
> from the output).

If I understand this correctly, you're thinking I'm talking about
*appending* a new line to the debug message. I'm talking about
*prepending*. So we're on the same page, the entire message is
formatted currently as "file:line:<debug message>".

I'm not sure I understand the last sentence, the debug message as
proposed in the patch is already a multi-line message.

> > Why do I care? I've been that guy trying to figure out a boot issue
> > with too much noise in the debug log messages pushing the messages I
> > needed to see off the screen (and the source wasn't readily available).
> > And no pager is not always an option if you have hundreds of pages of
> > log messages to scroll through, it takes forever.
> 
> As I have been in the same situation before, too, I second that. I would
> also like a feature so that debug messages (or all output) get spewn
> into a file (overwriting existing bytes similar to how grub_env works,
> acting like a ring buffer on the file). So you could boot some recovery
> envionment to create a sufficiently large file, set debug=all, let debug
> logs write into that file, and then analyze them after another reboot
> into said environment. Or when GRUB is booted from a USB key, the file
> can be created/analyzed on another machine.

Interesting idea. Also, I had thought of having an in memory ring-buffer
for playing back debug log on a live grub.

> 
> This may not help if nothing boots on that machine, but in my experience
> there is either some non-Linux operating system already installed on
> that machine that fails to boot Linux from GRUB, or at least a recovery
> environment from another OS can be booted.
> 
> > I don't think we need to agree (that is for you to agree that the issue
> > I'm describing is something to be concerned about). However, like I
> > said, I think we can both be satisfied by not leaving out the file:line
> > and to prepend "\n" to "add-symbol-file" so that it will start on a new
> > line. So I'll ask again. Is my proposal an acceptable modification for
> > the need that you have?
> 
> Another way (if possible, I don't know GRUB internals enough) would be
> to provide a module similar to lsmod that shows this output for all
> loaded modules. Users could load it if they want to use gdb and invoke
> it during their debug session. Then copy&paste the output in one single
> block.

That's another idea, a "get-gdb-symbol-file" command.

Glenn

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Michael Schierl]

Hello,


Am 18.10.2021 um 22:29 schrieb Glenn Washburn:

> I can't say I'm a fan of another special variable, but I'd also be fine
> with that route. Another route might be a (proc) file, eg. "/gsyms",
> which outputs add-symbol-file lines for all loaded modules. This could
> be put in its own module, eg. gdb-syms, which would address the
> increasing the core image size concern below.

To be honest I was not even aware that (proc) was a thing in Grub. In
fact, procfs is not loaded in any grub I have here, and loading it does
not make any files appear in it either (if I can trust the ls command).

> If I understand this correctly, you're thinking I'm talking about
> *appending* a new line to the debug message. I'm talking about
> *prepending*. So we're on the same page, the entire message is
> formatted currently as "file:line:<debug message>".
>
> I'm not sure I understand the last sentence, the debug message as
> proposed in the patch is already a multi-line message.

Ok, then rather "every fourth line" instead of "every second line"?

I have to admit I did not actually apply and test the patch. From the
patch content, when not using qdprintf, it looked to me that the output
would be similar to

kern/efi/init.c:2222 add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/kernel.exec \\
  40005678 -s .data 40009876
kern/dl.c:1111 add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/efidisk.debug \\
  10005678 -s .data 10009876
kern/dl.c:1111 add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/ext2.debug \\
  20005678 -s .data 20009876
kern/dl.c:1111 add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/gfxterm.debug \\
  30005678 -s .data 30009876
kern/dl.c:1111 add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/normal.debug \\
  30005678 -s .data 30009876


And with prepending a newline, it would look like this:

kern/efi/init.c.c:2222
add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/kernel.exec \\
  40005678 -s .data 40009876
kern/dl.c:1111
add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/efidisk.debug \\
  10005678 -s .data 10009876
kern/dl.c:1111
add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/ext2.debug \\
  20005678 -s .data 20009876
kern/dl.c:1111
add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/gfxterm.debug \\
  30005678 -s .data 30009876
kern/dl.c:1111
add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/normal.debug \\
  30005678 -s .data 30009876


And what you need to copy into gdb would be

add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/kernel.exec \\
  40005678 -s .data 40009876
add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/efidisk.debug \\
  10005678 -s .data 10009876
add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/ext2.debug \\
  20005678 -s .data 20009876
add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/gfxterm.debug \\
  30005678 -s .data 30009876
add-symbol-file \\
/usr/lib/debug/usr/lib/grub/x86_64-efi/normal.debug \\
  30005678 -s .data 30009876

If that assumption is wrong, I am sorry for misinterpreting the patch
and stealing your time.

> Interesting idea. Also, I had thought of having an in memory ring-buffer
> for playing back debug log on a live grub.

The interesting question is how to play it back as in my experience,
GRUB usually locks up when I need this. So there is no real way to
return to the shell so you could play it back again. (On the other hand,
this would require to synchronously write the logs to disk and not
buffer them, or you would miss the last few). But probably there are
other cases where you actually could return to the prompt.


Regards,


Michael

Re: [PATCH 2/2] Make a "gdb" dprintf that tells us load addresses.

[Glenn Washburn]

On Mon, 18 Oct 2021 23:04:59 +0200
Michael Schierl <schierlm@gmx.de> wrote:

> 
> Hello,
> 
> 
> Am 18.10.2021 um 22:29 schrieb Glenn Washburn:
> 
> > I can't say I'm a fan of another special variable, but I'd also be fine
> > with that route. Another route might be a (proc) file, eg. "/gsyms",
> > which outputs add-symbol-file lines for all loaded modules. This could
> > be put in its own module, eg. gdb-syms, which would address the
> > increasing the core image size concern below.
> 
> To be honest I was not even aware that (proc) was a thing in Grub. In
> fact, procfs is not loaded in any grub I have here, and loading it does
> not make any files appear in it either (if I can trust the ls command).

Its not much of a thing, though I have patches to make it more of a
thing. Afaik, the only thing that currently uses (proc) is cryptodisk
with luks.

> 
> > If I understand this correctly, you're thinking I'm talking about
> > *appending* a new line to the debug message. I'm talking about
> > *prepending*. So we're on the same page, the entire message is
> > formatted currently as "file:line:<debug message>".
> >
> > I'm not sure I understand the last sentence, the debug message as
> > proposed in the patch is already a multi-line message.
> 
> Ok, then rather "every fourth line" instead of "every second line"?
> 
> I have to admit I did not actually apply and test the patch. From the
> patch content, when not using qdprintf, it looked to me that the output
> would be similar to
> 
> kern/efi/init.c:2222 add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/kernel.exec \\
>   40005678 -s .data 40009876
> kern/dl.c:1111 add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/efidisk.debug \\
>   10005678 -s .data 10009876
> kern/dl.c:1111 add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/ext2.debug \\
>   20005678 -s .data 20009876
> kern/dl.c:1111 add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/gfxterm.debug \\
>   30005678 -s .data 30009876
> kern/dl.c:1111 add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/normal.debug \\
>   30005678 -s .data 30009876
> 
> 
> And with prepending a newline, it would look like this:
> 
> kern/efi/init.c.c:2222
> add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/kernel.exec \\
>   40005678 -s .data 40009876
> kern/dl.c:1111
> add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/efidisk.debug \\
>   10005678 -s .data 10009876
> kern/dl.c:1111
> add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/ext2.debug \\
>   20005678 -s .data 20009876
> kern/dl.c:1111
> add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/gfxterm.debug \\
>   30005678 -s .data 30009876
> kern/dl.c:1111
> add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/normal.debug \\
>   30005678 -s .data 30009876
> 
> 
> And what you need to copy into gdb would be
> 
> add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/kernel.exec \\
>   40005678 -s .data 40009876
> add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/efidisk.debug \\
>   10005678 -s .data 10009876
> add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/ext2.debug \\
>   20005678 -s .data 20009876
> add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/gfxterm.debug \\
>   30005678 -s .data 30009876
> add-symbol-file \\
> /usr/lib/debug/usr/lib/grub/x86_64-efi/normal.debug \\
>   30005678 -s .data 30009876
> 
> If that assumption is wrong, I am sorry for misinterpreting the patch
> and stealing your time.

I think we're on the same page now. I haven't tested the patch either,
but the above is my understanding as well (except that just one '\' is
output and the numbers are in '0x' prefixed hexidecimal). And I think I
understand now that you were giving helpful advice on the differences
in to extract the desired output of what I was proposing versus the
patch as is.

> > Interesting idea. Also, I had thought of having an in memory ring-buffer
> > for playing back debug log on a live grub.
> 
> The interesting question is how to play it back as in my experience,
> GRUB usually locks up when I need this. So there is no real way to
> return to the shell so you could play it back again. (On the other hand,
> this would require to synchronously write the logs to disk and not
> buffer them, or you would miss the last few). But probably there are
> other cases where you actually could return to the prompt.

Yes, I've had issues where the issue was due to required modules not
being loaded due to misconfiguration, but it wasn't obvious because the
debug output would flash by and then go back to the menu. So still had
a working grub. But, yes, I think your proposal satisfies more cases
and harder to debug ones, but both have their place (some setups don't
have writable disks at boot).

Glenn