[RFC][gdb/symtab] Add DEBUG_DEBUGINFOD_CLIENT in debuginfod-support.c

[RFC][gdb/symtab] Add DEBUG_DEBUGINFOD_CLIENT in debuginfod-support.c

[Tom de Vries]

Hi,

Add an off-by-default debug trace option DEBUG_DEBUGINFOD_CLIENT in
debuginfod-support.c.

By redefining DEBUG_DEBUGINFOD_CLIENT to 1, we get a trace like this:
...
TRYING DEBUGINFO FOR: \
  /home/vries/gdb_versions/devel/system-supplied DSO at 0x7ffff7ffa000
BUILDID: 157d01461677175219ab3ccd37454aeb740d2a7e
TOOK: 0.699193 seconds
RESULT fd: -2
warning: Source file is more recent than executable.
TRYING SOURCE: /home/abuild/rpmbuild/BUILD/gcc-7.5.0+r278197/\
  obj-x86_64-suse-linux/x86_64-suse-linux/libgcc/../../../libgcc/\
  config/i386/sfp-exceptions.c
BUILDID: 97481d83f99d6da01138fe4c61114da27e34d17e
TOOK: 1.724909 seconds
RESULT fd: -2
TRYING SOURCE: /home/abuild/rpmbuild/BUILD/gcc-7.5.0+r278197/\
  obj-x86_64-suse-linux/x86_64-suse-linux/libgcc/../../../libgcc/libgcc2.c
BUILDID: 97481d83f99d6da01138fe4c61114da27e34d17e
TOOK: 0.819237 seconds
RESULT fd: -2
...

Any comments?

Thanks,
- Tom

[gdb/symtab] Add DEBUG_DEBUGINFOD_CLIENT in debuginfod-support.c

gdb/ChangeLog:

2021-03-31  Tom de Vries  <tdevries@suse.de>

	* debuginfod-support.c (DEBUG_DEBUGINFOD_CLIENT): New macro.  Define
	to 0.
	(print_build_id, time_elapsed): New function.
	(debuginfod_source_query, debuginfod_debuginfo_query)
	[DEBUG_DEBUGINFOD_CLIENT]: Add tracing code.

---
 gdb/debuginfod-support.c | 52 ++++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 52 insertions(+)

diff --git a/gdb/debuginfod-support.c b/gdb/debuginfod-support.c
index 9778e2e4cfe..30b9f4ad631 100644
--- a/gdb/debuginfod-support.c
+++ b/gdb/debuginfod-support.c
@@ -23,6 +23,12 @@
 #include "debuginfod-support.h"
 #include "gdbsupport/gdb_optional.h"
 
+#define DEBUG_DEBUGINFOD_CLIENT 0
+
+#if DEBUG_DEBUGINFOD_CLIENT
+#include <chrono>
+#endif
+
 #ifndef HAVE_LIBDEBUGINFOD
 scoped_fd
 debuginfod_source_query (const unsigned char *build_id,
@@ -114,6 +120,28 @@ debuginfod_init ()
   return c;
 }
 
+#if DEBUG_DEBUGINFOD_CLIENT
+static void
+print_build_id (FILE *stream, const char *prefix, const unsigned char *build_id,
+		int build_id_len, const char *postfix)
+{
+  if (prefix)
+    fprintf (stream, "%s", prefix);
+  for (int i = 0; i < build_id_len; ++i)
+    fprintf (stream, "%02x", build_id[i]);
+  if (postfix)
+    fprintf (stream, "%s", postfix);
+}
+
+static double
+time_elapsed (std::chrono::time_point<std::chrono::high_resolution_clock> start)
+{
+  auto end = std::chrono::high_resolution_clock::now ();
+  std::chrono::duration<double> diff = end - start;
+  return diff.count ();
+}
+#endif
+
 /* See debuginfod-support.h  */
 
 scoped_fd
@@ -131,14 +159,26 @@ debuginfod_source_query (const unsigned char *build_id,
   if (c == nullptr)
     return scoped_fd (-ENOMEM);
 
+#if DEBUG_DEBUGINFOD_CLIENT
+  fprintf (stderr, "TRYING SOURCE: %s\n", srcpath);
+  print_build_id (stderr, "BUILDID: ", build_id, build_id_len, "\n");
+#endif
+
   user_data data ("source file", srcpath);
 
   debuginfod_set_user_data (c.get (), &data);
+#if DEBUG_DEBUGINFOD_CLIENT
+  auto start = std::chrono::high_resolution_clock::now ();
+#endif
   scoped_fd fd (debuginfod_find_source (c.get (),
 					build_id,
 					build_id_len,
 					srcpath,
 					nullptr));
+#if DEBUG_DEBUGINFOD_CLIENT
+  fprintf (stderr, "TOOK: %f seconds\n", time_elapsed (start));
+  fprintf (stderr, "RESULT fd: %d\n", fd.get ());
+#endif
 
   /* TODO: Add 'set debug debuginfod' command to control when error messages are shown.  */
   if (fd.get () < 0 && fd.get () != -ENOENT)
@@ -172,9 +212,21 @@ debuginfod_debuginfo_query (const unsigned char *build_id,
   char *dname = nullptr;
   user_data data ("separate debug info for", filename);
 
+#if DEBUG_DEBUGINFOD_CLIENT
+  fprintf (stderr, "TRYING DEBUGINFO FOR: %s\n", filename);
+  print_build_id (stderr, "BUILDID: ", build_id, build_id_len, "\n");
+#endif
+
   debuginfod_set_user_data (c.get (), &data);
+#if DEBUG_DEBUGINFOD_CLIENT
+  auto start = std::chrono::high_resolution_clock::now ();
+#endif
   scoped_fd fd (debuginfod_find_debuginfo (c.get (), build_id, build_id_len,
 					   &dname));
+#if DEBUG_DEBUGINFOD_CLIENT
+  fprintf (stderr, "TOOK: %f seconds\n", time_elapsed (start));
+  fprintf (stderr, "RESULT fd: %d\n", fd.get ());
+#endif
 
   if (fd.get () < 0 && fd.get () != -ENOENT)
     printf_filtered (_("Download failed: %s.  Continuing without debug info for %ps.\n"),

Re: [RFC][gdb/symtab] Add DEBUG_DEBUGINFOD_CLIENT in debuginfod-support.c

[Simon Marchi]

On 2021-03-31 9:56 a.m., Tom de Vries wrote:> Hi,
> 
> Add an off-by-default debug trace option DEBUG_DEBUGINFOD_CLIENT in
> debuginfod-support.c.
> 
> By redefining DEBUG_DEBUGINFOD_CLIENT to 1, we get a trace like this:
> ...
> TRYING DEBUGINFO FOR: \
>   /home/vries/gdb_versions/devel/system-supplied DSO at 0x7ffff7ffa000
> BUILDID: 157d01461677175219ab3ccd37454aeb740d2a7e
> TOOK: 0.699193 seconds
> RESULT fd: -2
> warning: Source file is more recent than executable.
> TRYING SOURCE: /home/abuild/rpmbuild/BUILD/gcc-7.5.0+r278197/\
>   obj-x86_64-suse-linux/x86_64-suse-linux/libgcc/../../../libgcc/\
>   config/i386/sfp-exceptions.c
> BUILDID: 97481d83f99d6da01138fe4c61114da27e34d17e
> TOOK: 1.724909 seconds
> RESULT fd: -2
> TRYING SOURCE: /home/abuild/rpmbuild/BUILD/gcc-7.5.0+r278197/\
>   obj-x86_64-suse-linux/x86_64-suse-linux/libgcc/../../../libgcc/libgcc2.c
> BUILDID: 97481d83f99d6da01138fe4c61114da27e34d17e
> TOOK: 0.819237 seconds
> RESULT fd: -2
> ...
> 
> Any comments?

Hi Tom,

I think this would be more useful if this was available using a "set
debug debuginfod" parameter, like the other debug printouts.

Simon

Re: [RFC][gdb/symtab] Add DEBUG_DEBUGINFOD_CLIENT in debuginfod-support.c

[Tom Tromey]

>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:

Tom> +print_build_id (FILE *stream, const char *prefix, const unsigned char *build_id,
Tom> +		int build_id_len, const char *postfix)
Tom> +{
Tom> +  if (prefix)
Tom> +    fprintf (stream, "%s", prefix);
Tom> +  for (int i = 0; i < build_id_len; ++i)
Tom> +    fprintf (stream, "%02x", build_id[i]);
Tom> +  if (postfix)

For prefix/postfix checks, use the '!= nullptr' form.

Tom