[PATCH] debuginfod: debuginfod client would cache negative results.

[PATCH] debuginfod: debuginfod client would cache negative results.

[Alice Zhang]

add debuginfod_config_cache for reading and writing to cache
configuration files, make use of the function within
debuginfod_clean_cache and debuginfod_query_server.

in debuginfod_query_server, create 000-permission file on failed
queries. Before querying each BUILDID, if corresponding 000 file
detected, compare its stat mtime with parameter from
.cache/cache_miss_s. if mtime is fresher, then return ENOENT and
exit; otherwise unlink the 000 file and proceed to a new query.

tests: add test in run-debuginfod-find.sh

test if the 000 file is created on failed query; if querying the
same failed BUILDID, whether the query should proceed without
going through server; set the cache_miss_s to 0 and query the same
buildid, and this time should go through the server.

Signed-off-by: Alice Zhang <alizhang@redhat.com>
---
 ChangeLog                      |   4 ++
 NEWS                           |   5 ++
 debuginfod/ChangeLog           |   4 ++
 debuginfod/debuginfod-client.c | 118 ++++++++++++++++++++++-----------
 tests/ChangeLog                |   4 ++
 tests/run-debuginfod-find.sh   |  37 +++++++++++
 6 files changed, 134 insertions(+), 38 deletions(-)

diff --git a/ChangeLog b/ChangeLog
index e18746fb..3c6f5cc0 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,7 @@
+2021-04-28  Alice Zhang  <azhang@redhat.com>
+        * debuginfod/debuginfod-client.c: Make client able to cache negative
+	results.
+	* tests/run-debuginfod-find.sh: Added tests for the feature.
 2021-03-30  Frank Ch. Eigler  <fche@redhat.com>
 
 	* configure.ac: Look for pthread_setname_np.
diff --git a/NEWS b/NEWS
index 038c6019..91c65160 100644
--- a/NEWS
+++ b/NEWS
@@ -2,6 +2,11 @@ Version 0.184
 
 debuginfod: Use libarchive's bsdtar as the .deb-family file unpacker.
 
+debuginfod-client: Now client would cache negative results. If a query
+                   for a file failed with 404, an empty 000 permission                    
+                   file is created, and this would save time by allowing
+                   skipping queries that are likely to fail.
+
 Version 0.183
 
 debuginfod: New thread-busy metric and more detailed error metrics.
diff --git a/debuginfod/ChangeLog b/debuginfod/ChangeLog
index ed2f77cf..520e66f9 100644
--- a/debuginfod/ChangeLog
+++ b/debuginfod/ChangeLog
@@ -1,3 +1,7 @@
+2021-05-04  Alice Zhang <alizhang@redhat.com>
+
+	* debuginfod-client.c: Make client able to cache negative results.
+
 2021-04-15  Frank Ch. Eigler <fche@redhat.com>
 
 	* debuginfod.cxx (groom): Only update database stats once.
diff --git a/debuginfod/debuginfod-client.c b/debuginfod/debuginfod-client.c
index d5e7bbdf..882e0386 100644
--- a/debuginfod/debuginfod-client.c
+++ b/debuginfod/debuginfod-client.c
@@ -131,6 +131,11 @@ struct debuginfod_client
 static const char *cache_clean_interval_filename = "cache_clean_interval_s";
 static const time_t cache_clean_default_interval_s = 86400; /* 1 day */
 
+/* The cache_miss_default_s within the debuginfod cache specifies how frequently
+   should the 000-permision file should be released.*/
+static const time_t cache_miss_default_s = 600; /* 10 min */
+static const char *cache_miss_filename = "cache_miss_s";
+
 /* The cache_max_unused_age_s file within the debuginfod cache specifies the
    the maximum time since last access that a file will remain in the cache.  */
 static const char *cache_max_unused_age_filename = "max_unused_age_s";
@@ -206,6 +211,38 @@ debuginfod_write_callback (char *ptr, size_t size, size_t nmemb, void *data)
   return (size_t) write(d->fd, (void*)ptr, count);
 }
 
+/* handle config file read and write */
+static int
+debuginfod_config_cache(char *config_path,
+                       long cache_config_default_s,
+		       struct stat *st)
+{
+  int fd;
+  /* if the config file doesn't exist, create one with DEFFILEMODE*/
+  if(stat(config_path, st) == -1)
+    {
+      fd = open(config_path, O_CREAT | O_RDWR, DEFFILEMODE);
+      if (fd < 0)
+        return -errno;
+
+      if (dprintf(fd, "%ld", cache_config_default_s) < 0)
+        return -errno;
+    }
+
+  long cache_config;
+  FILE *config_file = fopen(config_path, "r");
+  if (config_file)
+    {
+      if (fscanf(config_file, "%ld", &cache_config) != 1)
+        cache_config = cache_config_default_s;
+      fclose(config_file);
+    }
+  else
+    cache_config = cache_config_default_s;
+
+  return cache_config;
+}
+
 /* Create the cache and interval file if they do not already exist.
    Return 0 if cache and config file are initialized, otherwise return
    the appropriate error code.  */
@@ -251,52 +288,26 @@ debuginfod_clean_cache(debuginfod_client *c,
 		       char *cache_path, char *interval_path,
 		       char *max_unused_path)
 {
+  time_t clean_interval, max_unused_age;
+  int rc = -1;
   struct stat st;
-  FILE *interval_file;
-  FILE *max_unused_file;
-
-  if (stat(interval_path, &st) == -1)
-    {
-      /* Create new interval file.  */
-      interval_file = fopen(interval_path, "w");
 
-      if (interval_file == NULL)
-        return -errno;
-
-      int rc = fprintf(interval_file, "%ld", cache_clean_default_interval_s);
-      fclose(interval_file);
-
-      if (rc < 0)
-        return -errno;
-    }
+  /* Create new interval file.  */
+  rc = debuginfod_config_cache(interval_path, cache_clean_default_interval_s, &st);
+  if (rc < 0)
+    return rc;
+  clean_interval = (time_t)rc;
 
   /* Check timestamp of interval file to see whether cleaning is necessary.  */
-  time_t clean_interval;
-  interval_file = fopen(interval_path, "r");
-  if (interval_file)
-    {
-      if (fscanf(interval_file, "%ld", &clean_interval) != 1)
-        clean_interval = cache_clean_default_interval_s;
-      fclose(interval_file);
-    }
-  else
-    clean_interval = cache_clean_default_interval_s;
-
   if (time(NULL) - st.st_mtime < clean_interval)
     /* Interval has not passed, skip cleaning.  */
     return 0;
 
   /* Read max unused age value from config file.  */
-  time_t max_unused_age;
-  max_unused_file = fopen(max_unused_path, "r");
-  if (max_unused_file)
-    {
-      if (fscanf(max_unused_file, "%ld", &max_unused_age) != 1)
-        max_unused_age = cache_default_max_unused_age_s;
-      fclose(max_unused_file);
-    }
-  else
-    max_unused_age = cache_default_max_unused_age_s;
+  rc = debuginfod_config_cache(max_unused_path, cache_default_max_unused_age_s, &st);
+  if (rc < 0)
+    return rc;
+  max_unused_age = (time_t)rc;
 
   char * const dirs[] = { cache_path, NULL, };
 
@@ -500,6 +511,7 @@ debuginfod_query_server (debuginfod_client *c,
   char *cache_path = NULL;
   char *maxage_path = NULL;
   char *interval_path = NULL;
+  char *cache_miss_path = NULL;
   char *target_cache_dir = NULL;
   char *target_cache_path = NULL;
   char *target_cache_tmppath = NULL;
@@ -667,6 +679,7 @@ debuginfod_query_server (debuginfod_client *c,
 
   /* XXX combine these */
   xalloc_str (interval_path, "%s/%s", cache_path, cache_clean_interval_filename);
+  xalloc_str (cache_miss_path, "%s/%s", cache_path, cache_miss_filename);
   xalloc_str (maxage_path, "%s/%s", cache_path, cache_max_unused_age_filename);
 
   if (vfd >= 0)
@@ -690,6 +703,26 @@ debuginfod_query_server (debuginfod_client *c,
       goto out;
     }
 
+  struct stat st;
+  time_t cache_miss;
+  /* Check if the file exists and it's of permission 000*/
+  if (errno == EACCES && stat(target_cache_path, &st) == 0 
+		      && (st.st_mode & 0777) == 0)
+    {
+      rc = debuginfod_config_cache(cache_miss_path, cache_miss_default_s, &st);
+      if (rc < 0)
+        goto out;
+
+      cache_miss = (time_t)rc;
+      if (time(NULL) - st.st_mtime <= cache_miss)
+        {
+         rc = -ENOENT;
+         goto out;
+       }
+      else
+        unlink(target_cache_path);
+    }
+
   long timeout = default_timeout;
   const char* timeout_envvar = getenv(server_timeout_envvar);
   if (timeout_envvar != NULL)
@@ -708,7 +741,6 @@ debuginfod_query_server (debuginfod_client *c,
   /* thereafter, goto out0 on error*/
 
   /* create target directory in cache if not found.  */
-  struct stat st;
   if (stat(target_cache_dir, &st) == -1 && mkdir(target_cache_dir, 0700) < 0)
     {
       rc = -errno;
@@ -1032,6 +1064,15 @@ debuginfod_query_server (debuginfod_client *c,
         }
     } while (num_msg > 0);
 
+  /* create a 000-permission file named as $HOME/.cache
+   * if the query fails with ENOENT.*/
+  if (rc == -ENOENT)
+    {
+      int efd = open (target_cache_path, O_CREAT|O_EXCL, 0000);
+      if (efd >= 0)
+        close(efd);
+    }
+
   if (verified_handle == NULL)
     goto out1;
 
@@ -1113,6 +1154,7 @@ debuginfod_query_server (debuginfod_client *c,
   free (cache_path);
   free (maxage_path);
   free (interval_path);
+  free (cache_miss_path);
   free (target_cache_dir);
   free (target_cache_path);
   free (target_cache_tmppath);
diff --git a/tests/ChangeLog b/tests/ChangeLog
index ea44d20c..7bfe01f7 100644
--- a/tests/ChangeLog
+++ b/tests/ChangeLog
@@ -1,3 +1,7 @@
+2021-05-04  Alice Zhang  <alizhang@redhat.com>
+	
+	* run-debuginfod-find.sh: Added tests for the feature.
+
 2021-03-30  Frank Ch. Eigler  <fche@redhat.com>
 
 	* run-debuginfod-find.sh: Add thread comm checks.
diff --git a/tests/run-debuginfod-find.sh b/tests/run-debuginfod-find.sh
index 8213c8a4..0bdb44d1 100755
--- a/tests/run-debuginfod-find.sh
+++ b/tests/run-debuginfod-find.sh
@@ -152,6 +152,41 @@ testrun ${abs_builddir}/debuginfod_build_id_find -e F/prog 1
 
 ########################################################################
 
+# PR25628
+rm -rf $DEBUGINFOD_CACHE_PATH # clean it from previous tests
+
+# The query is designed to fail, while the 000-permission file should be created.
+testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo 01234567 || true
+if [ ! -f $DEBUGINFOD_CACHE_PATH/01234567/debuginfo ]; then
+  echo "could not find cache in $DEBUGINFOD_CACHE_PATH"
+  exit 1
+fi
+
+if [ -r $DEBUGINFOD_CACHE_PATH/01234567/debuginfo ]; then
+  echo "The cache $DEBUGINFOD_CACHE_PATH/01234567/debuginfo is readable"
+  exit 1
+fi
+
+bytecount_before=`curl -s http://127.0.0.1:$PORT1/metrics | grep 'http_responses_transfer_bytes_count{code="404"}'`
+testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo 01234567 || true
+bytecount_after=`curl -s http://127.0.0.1:$PORT1/metrics | grep 'http_responses_transfer_bytes_count{code="404"}'`
+if [ "$bytecount_before" != "$bytecount_after" ]; then
+  echo "http_responses_transfer_bytes_count{code="404"} has changed."
+  exit 1
+fi
+
+# set cache_miss_s to 0 and sleep 1 to make the mtime expire.
+echo 0 > $DEBUGINFOD_CACHE_PATH/cache_miss_s
+sleep 1
+bytecount_before=`curl -s http://127.0.0.1:$PORT1/metrics | grep 'http_responses_transfer_bytes_count{code="404"}'`
+testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo 01234567 || true
+bytecount_after=`curl -s http://127.0.0.1:$PORT1/metrics | grep 'http_responses_transfer_bytes_count{code="404"}'`
+if [ "$bytecount_before" == "$bytecount_after" ]; then
+  echo "http_responses_transfer_bytes_count{code="404"} should be incremented."
+  exit 1
+fi
+########################################################################
+
 # Test whether debuginfod-find is able to fetch those files.
 rm -rf $DEBUGINFOD_CACHE_PATH # clean it from previous tests
 filename=`testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo $BUILDID`
@@ -459,6 +494,7 @@ file -L L/foo
 export DEBUGINFOD_URLS=http://127.0.0.1:$PORT1
 rm -rf $DEBUGINFOD_CACHE_PATH
 testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo $BUILDID && false || true
+rm -f $DEBUGINFOD_CACHE_PATH/$BUILDID/debuginfo # drop 000-perm negative-hit file
 export DEBUGINFOD_URLS=http://127.0.0.1:$PORT2
 testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo $BUILDID
 
@@ -466,6 +502,7 @@ testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo $BUILDID
 export DEBUGINFOD_URLS=127.0.0.1:$PORT1
 rm -rf $DEBUGINFOD_CACHE_PATH
 testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo $BUILDID && false || true
+rm -f $DEBUGINFOD_CACHE_PATH/$BUILDID/debuginfo # drop 000-perm negative-hit file
 export DEBUGINFOD_URLS=127.0.0.1:$PORT2
 testrun ${abs_top_builddir}/debuginfod/debuginfod-find debuginfo $BUILDID
 
-- 
2.30.2

Re: [PATCH] debuginfod: debuginfod client would cache negative results.

[Mark Wielaard]

Hi Alice,

On Tue, May 04, 2021 at 04:25:59PM -0400, Alice Zhang via Elfutils-devel wrote:
> add debuginfod_config_cache for reading and writing to cache
> configuration files, make use of the function within
> debuginfod_clean_cache and debuginfod_query_server.
> 
> in debuginfod_query_server, create 000-permission file on failed
> queries. Before querying each BUILDID, if corresponding 000 file
> detected, compare its stat mtime with parameter from
> .cache/cache_miss_s. if mtime is fresher, then return ENOENT and
> exit; otherwise unlink the 000 file and proceed to a new query.
> 
> tests: add test in run-debuginfod-find.sh
> 
> test if the 000 file is created on failed query; if querying the
> same failed BUILDID, whether the query should proceed without
> going through server; set the cache_miss_s to 0 and query the same
> buildid, and this time should go through the server.

This looks really good. I rebased it, added slightly bigger ChangeLog
entries and reindented the code in places where it was > 80 chars and
pushed the result.

Thanks,

Mark