debuginfod: Accelerate traversal, shutdowns, improve metrics

Added new metrics for scanning that allow estimation of its reading
bandwidth.  Accelerated responsivity to SIGINT shutdown during
archive-scanning phase, which previously insisted on completely
processing the current archive.  Noted in systemd service file that in
the worst case, it might still take a long time.  Accelerated
traversals by moving regex -I/-X handling to apply to file names only
(as always documented), so directory traversal metrics are accurate
regardless of their name.

Signed-off-by: Frank Ch. Eigler <fche@redhat.com>

diff --git a/config/ChangeLog b/config/ChangeLog
index d280511..e5c41be 100644 (file)
--- a/config/ChangeLog
+++ b/config/ChangeLog
@@ -1,3 +1,7 @@
+2020-10-31  Frank Ch. Eigler  <fche@redhat.com>
+
+       * debuginfod.service: Bump up TimeoutStopSec.
+
 2020-10-30  Frank Ch. Eigler  <fche@redhat.com>
 
        * elfutils.spec.in: Fix debuginfod config/state file attributes

diff --git a/config/debuginfod.service b/config/debuginfod.service
index 8fca343..b64d8cb 100644 (file)
--- a/config/debuginfod.service
+++ b/config/debuginfod.service
@@ -9,7 +9,8 @@ User=debuginfod
 Group=debuginfod
 #CacheDirectory=debuginfod
 ExecStart=/usr/bin/debuginfod -d /var/cache/debuginfod/debuginfod.sqlite -p $DEBUGINFOD_PORT $DEBUGINFOD_VERBOSE $DEBUGINFOD_PRAGMAS $DEBUGINFOD_PATHS
-TimeoutStopSec=10
+# Stopping can take a long time if scanning of large archives is in progress
+TimeoutStopSec=60
 PrivateTmp=yes
 
 [Install]

diff --git a/debuginfod/ChangeLog b/debuginfod/ChangeLog
index ec791c6..34363e7 100644 (file)
--- a/debuginfod/ChangeLog
+++ b/debuginfod/ChangeLog
@@ -1,8 +1,16 @@
+2020-10-31  Frank Ch. Eigler  <fche@redhat.com>
+
+       * debuginfod.cxx (scan_source_file, scan_archive_file): Add new scanned_bytes_total,
+       scanned_files_total metrics.
+       (archive_classify): Exit early if interrupted.
+       (scan_source_paths): Perform realpath/regex checks only on FTS_F files.
+       Tweak metrics.
+
 2020-10-30  Frank Ch. Eigler  <fche@redhat.com>
 
        PR26775 cont'd.
-       (thread_main_scanner): Ensure control doesn't leave
-       infinite loop until program exit, even if SIGUSR2.
+       * debuginfod.cxx (thread_main_scanner): Ensure control doesn't
+       leave infinite loop until program exit, even if SIGUSR2.
        (scan_source_paths): Have traverser clean scanq on
        SIGUSR2.  Emit additional traversed_total metrics.
        (groom): Emit additional groomed_total metrics.

diff --git a/debuginfod/debuginfod.cxx b/debuginfod/debuginfod.cxx
index 1020a64..3085f38 100644 (file)
--- a/debuginfod/debuginfod.cxx
+++ b/debuginfod/debuginfod.cxx
@@ -1405,7 +1405,8 @@ handle_buildid_r_match (bool internal_req_p,
         throw libc_exception (errno, "cannot create temporary file");
       // NB: don't unlink (tmppath), as fdcache will take charge of it.
 
-      rc = archive_read_data_into_fd (a, fd);
+      // NB: this can take many uninterruptible seconds for a huge file
+      rc = archive_read_data_into_fd (a, fd); 
       if (rc != ARCHIVE_OK) // e.g. ENOSPC!
         {
           close (fd);
@@ -2228,7 +2229,9 @@ scan_source_file (const string& rps, const stat_t& st,
         elf_classify (fd, executable_p, debuginfo_p, buildid, sourcefiles);
       else
         throw libc_exception(errno, string("open ") + rps);
-      inc_metric ("scanned_total","source","file");
+      add_metric ("scanned_bytes_total","source","file",
+                  st.st_size);
+      inc_metric ("scanned_files_total","source","file");
     }
   // NB: we catch exceptions here too, so that we can
   // cache the corrupt-elf case (!executable_p &&
@@ -2411,9 +2414,12 @@ archive_classify (const string& rps, string& archive_extension,
   if (verbose > 3)
     obatched(clog) << "libarchive scanning " << rps << endl;
 
-  while(1) // parse cpio archive entries
+  while(1) // parse archive entries
     {
-      try
+    if (interrupted)
+      break;
+
+    try
         {
           struct archive_entry *e;
           rc = archive_read_next_header (a, &e);
@@ -2602,7 +2608,9 @@ scan_archive_file (const string& rps, const stat_t& st,
                         st.st_mtime,
                         my_fts_executable, my_fts_debuginfo, my_fts_sref, my_fts_sdef,
                         my_fts_sref_complete_p);
-      inc_metric ("scanned_total","source",archive_extension + " archive");
+      add_metric ("scanned_bytes_total","source",archive_extension + " archive",
+                  st.st_size);
+      inc_metric ("scanned_files_total","source",archive_extension + " archive");
       add_metric("found_debuginfo_total","source",archive_extension + " archive",
                  my_fts_debuginfo);
       add_metric("found_executable_total","source",archive_extension + " archive",
@@ -2808,35 +2816,39 @@ scan_source_paths()
     if (verbose > 2)
       obatched(clog) << "fts traversing " << f->fts_path << endl;
 
-    /* Found a file.  Convert it to an absolute path, so
-       the buildid database does not have relative path
-       names that are unresolvable from a subsequent run
-       in a different cwd. */
-    char *rp = realpath(f->fts_path, NULL);
-    if (rp == NULL)
-      continue; // ignore dangling symlink or such
-    string rps = string(rp);
-    free (rp);
-
-    bool ri = !regexec (&file_include_regex, rps.c_str(), 0, 0, 0);
-    bool rx = !regexec (&file_exclude_regex, rps.c_str(), 0, 0, 0);
-    if (!ri || rx)
-      {
-        if (verbose > 3)
-          obatched(clog) << "fts skipped by regex " << (!ri ? "I" : "") << (rx ? "X" : "") << endl;
-        fts_regex ++;
-        if (!ri)
-          inc_metric("traversed_total","type","regex-skipped-I");
-        if (rx)
-          inc_metric("traversed_total","type","regex-skipped-X");
-        continue;
-      }
-
     switch (f->fts_info)
       {
       case FTS_F:
-        scanq.push_back (make_pair(rps, *f->fts_statp));
-        inc_metric("traversed_total","type","file");
+        {
+          /* Found a file.  Convert it to an absolute path, so
+             the buildid database does not have relative path
+             names that are unresolvable from a subsequent run
+             in a different cwd. */
+          char *rp = realpath(f->fts_path, NULL);
+          if (rp == NULL)
+            continue; // ignore dangling symlink or such
+          string rps = string(rp);
+          free (rp);
+          
+          bool ri = !regexec (&file_include_regex, rps.c_str(), 0, 0, 0);
+          bool rx = !regexec (&file_exclude_regex, rps.c_str(), 0, 0, 0);
+          if (!ri || rx)
+            {
+              if (verbose > 3)
+                obatched(clog) << "fts skipped by regex "
+                               << (!ri ? "I" : "") << (rx ? "X" : "") << endl;
+              fts_regex ++;
+              if (!ri)
+                inc_metric("traversed_total","type","file-skipped-I");
+              if (rx)
+                inc_metric("traversed_total","type","file-skipped-X");
+            }
+          else
+            {
+              scanq.push_back (make_pair(rps, *f->fts_statp));
+              inc_metric("traversed_total","type","file");
+            }
+        }
         break;
 
       case FTS_ERR:
@@ -2849,6 +2861,10 @@ scan_source_paths()
         inc_metric("traversed_total","type","error");
         break;
 
+      case FTS_SL: // ignore, but count because debuginfod -L would traverse these
+        inc_metric("traversed_total","type","symlink");
+        break;
+
       case FTS_D: // ignore
         inc_metric("traversed_total","type","directory");
         break;

diff --git a/tests/ChangeLog b/tests/ChangeLog
index af8ece6..57fc4c8 100644 (file)
--- a/tests/ChangeLog
+++ b/tests/ChangeLog
@@ -15,6 +15,10 @@
        pthread_join.
        * vdsosyms.c (main): Call dwfl_end.
 
+2020-10-31  Frank Ch. Eigler  <fche@redhat.com>
+
+       * run-debuginfod-find.sh: Modify for tweaked/new metrics.
+
 2020-10-30  Frank Ch. Eigler  <fche@redhat.com>
 
        PR26775

diff --git a/tests/run-debuginfod-find.sh b/tests/run-debuginfod-find.sh
index 0d1fcf1..48dbc7d 100755 (executable)
--- a/tests/run-debuginfod-find.sh
+++ b/tests/run-debuginfod-find.sh
@@ -246,11 +246,11 @@ cp -rvp ${abs_srcdir}/debuginfod-tars Z
 kill -USR1 $PID1
 # All rpms need to be in the index, except the dummy permission-000 one
 rpms=$(find R -name \*rpm | grep -v nothing | wc -l)
-wait_ready $PORT1 'scanned_total{source=".rpm archive"}' $rpms
+wait_ready $PORT1 'scanned_files_total{source=".rpm archive"}' $rpms
 txz=$(find Z -name \*tar.xz | wc -l)
-wait_ready $PORT1 'scanned_total{source=".tar.xz archive"}' $txz
+wait_ready $PORT1 'scanned_files_total{source=".tar.xz archive"}' $txz
 tb2=$(find Z -name \*tar.bz2 | wc -l)
-wait_ready $PORT1 'scanned_total{source=".tar.bz2 archive"}' $tb2
+wait_ready $PORT1 'scanned_files_total{source=".tar.bz2 archive"}' $tb2
 
 kill -USR1 $PID1  # two hits of SIGUSR1 may be needed to resolve .debug->dwz->srefs
 # Expect all source files found in the rpms (they are all called hello.c :)
@@ -419,9 +419,9 @@ if type bsdtar 2>/dev/null; then
     kill -USR1 $PID2
     # All debs need to be in the index
     debs=$(find D -name \*.deb | wc -l)
-    wait_ready $PORT2 'scanned_total{source=".deb archive"}' `expr $debs`
+    wait_ready $PORT2 'scanned_files_total{source=".deb archive"}' `expr $debs`
     ddebs=$(find D -name \*.ddeb | wc -l)
-    wait_ready $PORT2 'scanned_total{source=".ddeb archive"}' `expr $ddebs`
+    wait_ready $PORT2 'scanned_files_total{source=".ddeb archive"}' `expr $ddebs`
 
     # ubuntu
     archive_test f17a29b5a25bd4960531d82aa6b07c8abe84fa66 "" ""
@@ -478,6 +478,8 @@ curl -s http://127.0.0.1:$PORT1/metrics | grep 'http_responses_transfer_bytes_co
 curl -s http://127.0.0.1:$PORT1/metrics | grep 'http_responses_transfer_bytes_sum'
 curl -s http://127.0.0.1:$PORT1/metrics | grep 'fdcache_'
 curl -s http://127.0.0.1:$PORT1/metrics | grep 'error_count'
+curl -s http://127.0.0.1:$PORT1/metrics | grep 'traversed_total'
+curl -s http://127.0.0.1:$PORT1/metrics | grep 'scanned_bytes_total'
 
 # And generate a few errors into the second debuginfod's logs, for analysis just below
 curl -s http://127.0.0.1:$PORT2/badapi > /dev/null || true