rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Frank Ch. Eigler]

    debuginfod: usability tweaks, incl. $DEBUGINFOD_PROGRESS client support
    
    This facility allows a default progress-printing function
    to be installed if the given environment variable is set.
    Some larger usage experience (systemtap/kernels) indicates
    the default timeout is too short, so bumped it to 30s.
    
    Signed-off-by: Frank Ch. Eigler <fche@redhat.com>

diff --git a/debuginfod/ChangeLog b/debuginfod/ChangeLog
index 8aa2944..a9483d0 100644
--- a/debuginfod/ChangeLog
+++ b/debuginfod/ChangeLog
@@ -1,3 +1,13 @@
+2019-12-04  Frank Ch. Eigler  <fche@redhat.com>
+
+	* debuginfod-client.c (default_progressfn): New function.
+	(debuginfod_begin): Use it if $DEBUGINFOD_PROGRESS set.
+	(server_timeout): Bump to 30 seconds.
+	(debuginfod_query_server): Call progressfn -after- rather than
+	before curl ops, to make it likely that a successful transfer
+	results in final a=b call.  Tweak cleanup sequence.
+	* debuginfod.h: Document $DEBUGINFOD_PROGRESS name.
+
 2019-11-26  Mark Wielaard  <mark@klomp.org>
 
 	* Makefile.am (BUILD_STATIC): Add needed libraries for libdw and
diff --git a/debuginfod/debuginfod-client.c b/debuginfod/debuginfod-client.c
index 6e62b86..3ee5e48 100644
--- a/debuginfod/debuginfod-client.c
+++ b/debuginfod/debuginfod-client.c
@@ -40,6 +40,7 @@
 
 #include "config.h"
 #include "debuginfod.h"
+#include "lib/system.h"
 #include <assert.h>
 #include <dirent.h>
 #include <stdio.h>
@@ -107,7 +108,7 @@ static const char url_delim_char = ' ';
 /* Timeout for debuginfods, in seconds.
    This env var must be set for debuginfod-client to run.  */
 static const char *server_timeout_envvar = DEBUGINFOD_TIMEOUT_ENV_VAR;
-static int server_timeout = 5;
+static int server_timeout = 30;
 
 /* Data associated with a particular CURL easy handle. Passed to
    the write callback.  */
@@ -511,6 +512,28 @@ debuginfod_query_server (debuginfod_client *c,
     {
       CURLMcode curl_res;
 
+      /* Wait 1 second, the minimum DEBUGINFOD_TIMEOUT.  */
+      curl_multi_wait(curlm, NULL, 0, 1000, NULL);
+
+      /* If the target file has been found, abort the other queries.  */
+      if (target_handle != NULL)
+        for (int i = 0; i < num_urls; i++)
+          if (data[i].handle != target_handle)
+            curl_multi_remove_handle(curlm, data[i].handle);
+
+      curl_res = curl_multi_perform(curlm, &still_running);
+
+      if (curl_res != CURLM_OK)
+        {
+          switch (curl_res)
+            {
+            case CURLM_CALL_MULTI_PERFORM: continue;
+            case CURLM_OUT_OF_MEMORY: rc = -ENOMEM; break;
+            default: rc = -ENETUNREACH; break;
+            }
+          goto out1;
+        }
+
       if (c->progressfn) /* inform/check progress callback */
         {
           loops ++;
@@ -554,27 +577,6 @@ debuginfod_query_server (debuginfod_client *c,
           if ((*c->progressfn) (c, pa, pb))
             break;
         }
-
-      /* Wait 1 second, the minimum DEBUGINFOD_TIMEOUT.  */
-      curl_multi_wait(curlm, NULL, 0, 1000, NULL);
-
-      /* If the target file has been found, abort the other queries.  */
-      if (target_handle != NULL)
-        for (int i = 0; i < num_urls; i++)
-          if (data[i].handle != target_handle)
-            curl_multi_remove_handle(curlm, data[i].handle);
-
-      curl_res = curl_multi_perform(curlm, &still_running);
-      if (curl_res != CURLM_OK)
-        {
-          switch (curl_res)
-            {
-            case CURLM_CALL_MULTI_PERFORM: continue;
-            case CURLM_OUT_OF_MEMORY: rc = -ENOMEM; break;
-            default: rc = -ENETUNREACH; break;
-            }
-          goto out1;
-        }
     } while (still_running);
 
   /* Check whether a query was successful. If so, assign its handle
@@ -673,9 +675,9 @@ debuginfod_query_server (debuginfod_client *c,
 
   curl_multi_cleanup(curlm);
   unlink (target_cache_tmppath);
+  close (fd); /* before the rmdir, otherwise it'll fail */
   (void) rmdir (target_cache_dir); /* nop if not empty */
   free(data);
-  close (fd);
 
  out0:
   free (server_urls);
@@ -684,6 +686,35 @@ debuginfod_query_server (debuginfod_client *c,
   return rc;
 }
 
+
+/* Activate a basic form of progress tracing */
+static int
+default_progressfn (debuginfod_client *c, long a, long b)
+{
+  (void) c;
+
+  int fd = open(getenv(DEBUGINFOD_PROGRESS_ENV_VAR),
+		O_APPEND|O_WRONLY|O_CREAT, 0666);
+  if (fd < 0)
+    goto out;
+
+  char *msg = NULL;
+  int rc = asprintf(&msg,
+		    "Downloading from debuginfod %ld/%ld%s", a, b,
+		    ((a == b) ? "\n" : "\r")); /* XXX: include URL - stateful */
+  if (rc < 0)
+    goto out1;
+
+  (void) write_retry(fd, msg, rc);
+  free (msg);
+
+  out1:
+    close (fd);
+  out:
+    return 0;
+}
+
+
 /* See debuginfod.h  */
 debuginfod_client  *
 debuginfod_begin (void)
@@ -692,7 +723,12 @@ debuginfod_begin (void)
   size_t size = sizeof (struct debuginfod_client);
   client = (debuginfod_client *) malloc (size);
   if (client != NULL)
-    client->progressfn = NULL;
+    {
+      if (getenv(DEBUGINFOD_PROGRESS_ENV_VAR))
+	client->progressfn = default_progressfn;
+      else
+	client->progressfn = NULL;
+    }
   return client;
 }
 
diff --git a/debuginfod/debuginfod.h b/debuginfod/debuginfod.h
index 6b1b1cc..33fae86 100644
--- a/debuginfod/debuginfod.h
+++ b/debuginfod/debuginfod.h
@@ -33,6 +33,7 @@
 #define DEBUGINFOD_URLS_ENV_VAR "DEBUGINFOD_URLS"
 #define DEBUGINFOD_CACHE_PATH_ENV_VAR "DEBUGINFOD_CACHE_PATH"
 #define DEBUGINFOD_TIMEOUT_ENV_VAR "DEBUGINFOD_TIMEOUT"
+#define DEBUGINFOD_PROGRESS_ENV_VAR "DEBUGINFOD_PROGRESS"
 
 /* Handle for debuginfod-client connection.  */
 typedef struct debuginfod_client debuginfod_client;
diff --git a/doc/ChangeLog b/doc/ChangeLog
index 00a61ac..9542161 100644
--- a/doc/ChangeLog
+++ b/doc/ChangeLog
@@ -1,3 +1,9 @@
+2019-12-04  Frank Ch. Eigler  <fche@redhat.com>
+
+	* debuginfod-find.1: Bump default timeout to 30.
+	* debuginfod_find_debuginfo.3: Ditto.
+	Document $DEBUGINFOD_PROGRESS.
+
 2019-09-02  Mark Wielaard  <mark@klomp.org>
 
 	* readelf.1 (symbols): Add optional section name.
diff --git a/doc/debuginfod-find.1 b/doc/debuginfod-find.1
index a759ecb..7f14e8c 100644
--- a/doc/debuginfod-find.1
+++ b/doc/debuginfod-find.1
@@ -121,7 +121,7 @@ debuginfod instances.  Alternate URL prefixes are separated by space.
 .B DEBUGINFOD_TIMEOUT
 This environment variable governs the timeout for each debuginfod HTTP
 connection.  A server that fails to respond within this many seconds
-is skipped.  The default is 5.
+is skipped.  The default is 30.
 
 .TP 21
 .B DEBUGINFOD_CACHE_PATH
diff --git a/doc/debuginfod_find_debuginfo.3 b/doc/debuginfod_find_debuginfo.3
index be8eed0..63766b3 100644
--- a/doc/debuginfod_find_debuginfo.3
+++ b/doc/debuginfod_find_debuginfo.3
@@ -165,7 +165,15 @@ debuginfod instances.  Alternate URL prefixes are separated by space.
 .B DEBUGINFOD_TIMEOUT
 This environment variable governs the timeout for each debuginfod HTTP
 connection.  A server that fails to respond within this many seconds
-is skipped.  The default is 5.
+is skipped.  The default is 30.
+
+.TP 21
+.B DEBUGINFOD_PROGRESS
+This environment variable governs the default progress function.  If
+set, and if a progressfn is not explicitly set, then the library will
+configure a default progressfn.  This function will append a simple
+progress message periodically to the given file.  Consider using
+"/dev/stderr" on platforms that support it.  The default is nothing.
 
 .TP 21
 .B DEBUGINFOD_CACHE_PATH
diff --git a/tests/ChangeLog b/tests/ChangeLog
index 6e3923f..d63d0eb 100644
--- a/tests/ChangeLog
+++ b/tests/ChangeLog
@@ -1,3 +1,7 @@
+2019-12-04  Frank Ch. Eigler  <fche@redhat.com>
+
+	* run-debuinfod-find.sh: Test $DEBUGINFOD_PROGRESS.
+
 2019-11-26  Mark Wielaard  <mark@klomp.org>
 
 	* Makefile.am (BUILD_STATIC): Add libraries needed for libdw.
diff --git a/tests/run-debuginfod-find.sh b/tests/run-debuginfod-find.sh
index 0ade03b..be6d565 100755
--- a/tests/run-debuginfod-find.sh
+++ b/tests/run-debuginfod-find.sh
@@ -153,8 +153,11 @@ cmp $filename F/prog2
 cat vlog
 grep -q Progress vlog
 tempfiles vlog
-filename=`testrun ${abs_top_builddir}/debuginfod/debuginfod-find executable $BUILDID2`
+filename=`testrun env DEBUGINFOD_PROGRESS=vlog2 ${abs_top_builddir}/debuginfod/debuginfod-find executable $BUILDID2`
 cmp $filename F/prog2
+cat vlog2
+grep -q Downloading vlog2
+tempfiles vlog2
 filename=`testrun ${abs_top_builddir}/debuginfod/debuginfod-find source $BUILDID2 ${PWD}/prog2.c`
 cmp $filename ${PWD}/prog2.c
 

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Mark Wielaard]

Hi Frank,

On Wed, 2019-12-04 at 16:10 -0500, Frank Ch. Eigler wrote:
>     debuginfod: usability tweaks, incl. $DEBUGINFOD_PROGRESS client
> support
>     
>     This facility allows a default progress-printing function
>     to be installed if the given environment variable is set.

I like this idea but have a bit of a security concern about the ability
to set it to any file. If someone manages to set it then they can
overwrite anything a process using the library can write to. I rather
it would just use stderr always when set since it is only meant as a
human debugging device.

>     Some larger usage experience (systemtap/kernels) indicates
>     the default timeout is too short, so bumped it to 30s.

My first thought is that we might need two timeouts. The original 5s
timeout is a good inactivity timeout, if the server couldn't be
connected to in 5 seconds, doesn't provide a response within 5 seconds
or a download doesn't see new data within 5 seconds that probably means
the data won't arrive, or too slow to be useful. But for larger data we
might want a timeout for the total download time, maybe 30 seconds is
too low for that. Given how large kernel debuginfo is it might take
several minutes.

libcurl does say about CURLOPT_TIMEOUT: "Since this option puts a hard
limit on how long time a request is  allowed to take, it has limited
use in dynamic use cases with varying transfer times. That is
especially apparent when using the multi interface, which may queue the
transfer, and that time is included." And it also has a
CURLOPT_CONNECTTIMEOUT option.

>     Signed-off-by: Frank Ch. Eigler <fche@redhat.com>
> 
> diff --git a/debuginfod/ChangeLog b/debuginfod/ChangeLog
> index 8aa2944..a9483d0 100644
> --- a/debuginfod/ChangeLog
> +++ b/debuginfod/ChangeLog
> @@ -1,3 +1,13 @@
> +2019-12-04  Frank Ch. Eigler  <fche@redhat.com>
> +
> +	* debuginfod-client.c (default_progressfn): New function.
> +	(debuginfod_begin): Use it if $DEBUGINFOD_PROGRESS set.
> +	(server_timeout): Bump to 30 seconds.
> +	(debuginfod_query_server): Call progressfn -after- rather than
> +	before curl ops, to make it likely that a successful transfer
> +	results in final a=b call.  Tweak cleanup sequence.
> +	* debuginfod.h: Document $DEBUGINFOD_PROGRESS name.
> +
>  2019-11-26  Mark Wielaard  <mark@klomp.org>
>  
>  	* Makefile.am (BUILD_STATIC): Add needed libraries for libdw and
> diff --git a/debuginfod/debuginfod-client.c b/debuginfod/debuginfod-client.c
> index 6e62b86..3ee5e48 100644
> --- a/debuginfod/debuginfod-client.c
> +++ b/debuginfod/debuginfod-client.c
> @@ -40,6 +40,7 @@
>  
>  #include "config.h"
>  #include "debuginfod.h"
> +#include "lib/system.h"
>  #include <assert.h>
>  #include <dirent.h>
>  #include <stdio.h>
> @@ -107,7 +108,7 @@ static const char url_delim_char = ' ';
>  /* Timeout for debuginfods, in seconds.
>     This env var must be set for debuginfod-client to run.  */
>  static const char *server_timeout_envvar = DEBUGINFOD_TIMEOUT_ENV_VAR;
> -static int server_timeout = 5;
> +static int server_timeout = 30;

So maybe have a new DEBUGINFOD_PROGRESS_TIMEOUT environment variable
with the original 5 second default, which would timeout the connection
if it doesn't succeed within 5 seconds, or if the download didn't see
any progress within the progress_timeout?

Then you could increase the server_timeout to something larger, say 60
seconds, which might be more appropriate for larger debuginfo files?

>  /* Data associated with a particular CURL easy handle. Passed to
>     the write callback.  */
> @@ -511,6 +512,28 @@ debuginfod_query_server (debuginfod_client *c,
>      {
>        CURLMcode curl_res;
>  
> +      /* Wait 1 second, the minimum DEBUGINFOD_TIMEOUT.  */
> +      curl_multi_wait(curlm, NULL, 0, 1000, NULL);
> +
> +      /* If the target file has been found, abort the other queries.  */
> +      if (target_handle != NULL)
> +        for (int i = 0; i < num_urls; i++)
> +          if (data[i].handle != target_handle)
> +            curl_multi_remove_handle(curlm, data[i].handle);
> +
> +      curl_res = curl_multi_perform(curlm, &still_running);
> +
> +      if (curl_res != CURLM_OK)
> +        {
> +          switch (curl_res)
> +            {
> +            case CURLM_CALL_MULTI_PERFORM: continue;
> +            case CURLM_OUT_OF_MEMORY: rc = -ENOMEM; break;
> +            default: rc = -ENETUNREACH; break;
> +            }
> +          goto out1;
> +        }
> +
>        if (c->progressfn) /* inform/check progress callback */
>          {
>            loops ++;
> @@ -554,27 +577,6 @@ debuginfod_query_server (debuginfod_client *c,
>            if ((*c->progressfn) (c, pa, pb))
>              break;
>          }
> -
> -      /* Wait 1 second, the minimum DEBUGINFOD_TIMEOUT.  */
> -      curl_multi_wait(curlm, NULL, 0, 1000, NULL);
> -
> -      /* If the target file has been found, abort the other queries.  */
> -      if (target_handle != NULL)
> -        for (int i = 0; i < num_urls; i++)
> -          if (data[i].handle != target_handle)
> -            curl_multi_remove_handle(curlm, data[i].handle);
> -
> -      curl_res = curl_multi_perform(curlm, &still_running);
> -      if (curl_res != CURLM_OK)
> -        {
> -          switch (curl_res)
> -            {
> -            case CURLM_CALL_MULTI_PERFORM: continue;
> -            case CURLM_OUT_OF_MEMORY: rc = -ENOMEM; break;
> -            default: rc = -ENETUNREACH; break;
> -            }
> -          goto out1;
> -        }
>      } while (still_running);

This seems to mean that if there is an error then the progress function
is never called, is that intended? Also for CURLM_CALL_MULTI_PERFORM we
continue/skip the progress function.

>    /* Check whether a query was successful. If so, assign its handle
> @@ -673,9 +675,9 @@ debuginfod_query_server (debuginfod_client *c,
>  
>    curl_multi_cleanup(curlm);
>    unlink (target_cache_tmppath);
> +  close (fd); /* before the rmdir, otherwise it'll fail */
>    (void) rmdir (target_cache_dir); /* nop if not empty */
>    free(data);
> -  close (fd);

This looks good. Just surprising. I assumed unlinking the file was
enough.

>   out0:
>    free (server_urls);
> @@ -684,6 +686,35 @@ debuginfod_query_server (debuginfod_client *c,
>    return rc;
>  }
>  
> +
> +/* Activate a basic form of progress tracing */
> +static int
> +default_progressfn (debuginfod_client *c, long a, long b)
> +{
> +  (void) c;
> +
> +  int fd = open(getenv(DEBUGINFOD_PROGRESS_ENV_VAR),
> +		O_APPEND|O_WRONLY|O_CREAT, 0666);
> +  if (fd < 0)
> +    goto out;
> +
> +  char *msg = NULL;
> +  int rc = asprintf(&msg,
> +		    "Downloading from debuginfod %ld/%ld%s", a, b,
> +		    ((a == b) ? "\n" : "\r")); /* XXX: include URL - stateful */
> +  if (rc < 0)
> +    goto out1;
> +
> +  (void) write_retry(fd, msg, rc);
> +  free (msg);
> +
> +  out1:
> +    close (fd);
> +  out:
> +    return 0;
> +}

The \r \n trick is nice.
Just always using stderr would simplify this a bit.
Also note that you can use dprintf to printf to a file descriptor. 

>  /* See debuginfod.h  */
>  debuginfod_client  *
>  debuginfod_begin (void)
> @@ -692,7 +723,12 @@ debuginfod_begin (void)
>    size_t size = sizeof (struct debuginfod_client);
>    client = (debuginfod_client *) malloc (size);
>    if (client != NULL)
> -    client->progressfn = NULL;
> +    {
> +      if (getenv(DEBUGINFOD_PROGRESS_ENV_VAR))
> +	client->progressfn = default_progressfn;
> +      else
> +	client->progressfn = NULL;
> +    }
>    return client;
>  }

OK. 

> diff --git a/debuginfod/debuginfod.h b/debuginfod/debuginfod.h
> index 6b1b1cc..33fae86 100644
> --- a/debuginfod/debuginfod.h
> +++ b/debuginfod/debuginfod.h
> @@ -33,6 +33,7 @@
>  #define DEBUGINFOD_URLS_ENV_VAR "DEBUGINFOD_URLS"
>  #define DEBUGINFOD_CACHE_PATH_ENV_VAR "DEBUGINFOD_CACHE_PATH"
>  #define DEBUGINFOD_TIMEOUT_ENV_VAR "DEBUGINFOD_TIMEOUT"
> +#define DEBUGINFOD_PROGRESS_ENV_VAR "DEBUGINFOD_PROGRESS"
>  
>  /* Handle for debuginfod-client connection.  */
>  typedef struct debuginfod_client debuginfod_client;
> diff --git a/doc/ChangeLog b/doc/ChangeLog
> index 00a61ac..9542161 100644
> --- a/doc/ChangeLog
> +++ b/doc/ChangeLog
> @@ -1,3 +1,9 @@
> +2019-12-04  Frank Ch. Eigler  <fche@redhat.com>
> +
> +	* debuginfod-find.1: Bump default timeout to 30.
> +	* debuginfod_find_debuginfo.3: Ditto.
> +	Document $DEBUGINFOD_PROGRESS.
> +
>  2019-09-02  Mark Wielaard  <mark@klomp.org>
>  
>  	* readelf.1 (symbols): Add optional section name.
> diff --git a/doc/debuginfod-find.1 b/doc/debuginfod-find.1
> index a759ecb..7f14e8c 100644
> --- a/doc/debuginfod-find.1
> +++ b/doc/debuginfod-find.1
> @@ -121,7 +121,7 @@ debuginfod instances.  Alternate URL prefixes are separated by space.
>  .B DEBUGINFOD_TIMEOUT
>  This environment variable governs the timeout for each debuginfod HTTP
>  connection.  A server that fails to respond within this many seconds
> -is skipped.  The default is 5.
> +is skipped.  The default is 30.
>  
>  .TP 21
>  .B DEBUGINFOD_CACHE_PATH
> diff --git a/doc/debuginfod_find_debuginfo.3 b/doc/debuginfod_find_debuginfo.3
> index be8eed0..63766b3 100644
> --- a/doc/debuginfod_find_debuginfo.3
> +++ b/doc/debuginfod_find_debuginfo.3
> @@ -165,7 +165,15 @@ debuginfod instances.  Alternate URL prefixes are separated by space.
>  .B DEBUGINFOD_TIMEOUT
>  This environment variable governs the timeout for each debuginfod HTTP
>  connection.  A server that fails to respond within this many seconds
> -is skipped.  The default is 5.
> +is skipped.  The default is 30.
> +
> +.TP 21
> +.B DEBUGINFOD_PROGRESS
> +This environment variable governs the default progress function.  If
> +set, and if a progressfn is not explicitly set, then the library will
> +configure a default progressfn.  This function will append a simple
> +progress message periodically to the given file.  Consider using
> +"/dev/stderr" on platforms that support it.  The default is nothing.
>
>  .TP 21
>  .B DEBUGINFOD_CACHE_PATH
> diff --git a/tests/ChangeLog b/tests/ChangeLog
> index 6e3923f..d63d0eb 100644
> --- a/tests/ChangeLog
> +++ b/tests/ChangeLog
> @@ -1,3 +1,7 @@
> +2019-12-04  Frank Ch. Eigler  <fche@redhat.com>
> +
> +	* run-debuinfod-find.sh: Test $DEBUGINFOD_PROGRESS.
> +
>  2019-11-26  Mark Wielaard  <mark@klomp.org>
>  
>  	* Makefile.am (BUILD_STATIC): Add libraries needed for libdw.
> diff --git a/tests/run-debuginfod-find.sh b/tests/run-debuginfod-find.sh
> index 0ade03b..be6d565 100755
> --- a/tests/run-debuginfod-find.sh
> +++ b/tests/run-debuginfod-find.sh
> @@ -153,8 +153,11 @@ cmp $filename F/prog2
>  cat vlog
>  grep -q Progress vlog
>  tempfiles vlog
> -filename=`testrun ${abs_top_builddir}/debuginfod/debuginfod-find executable $BUILDID2`
> +filename=`testrun env DEBUGINFOD_PROGRESS=vlog2 ${abs_top_builddir}/debuginfod/debuginfod-find executable $BUILDID2`
>  cmp $filename F/prog2
> +cat vlog2
> +grep -q Downloading vlog2
> +tempfiles vlog2
>  filename=`testrun ${abs_top_builddir}/debuginfod/debuginfod-find source $BUILDID2 ${PWD}/prog2.c`
>  cmp $filename ${PWD}/prog2.c

To test if you just use /dev/stderr would just need to redirect stderr
to a file.

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Frank Ch. Eigler]

Hi -

> >     debuginfod: usability tweaks, incl. $DEBUGINFOD_PROGRESS client
> > support
> >     
> >     This facility allows a default progress-printing function
> >     to be installed if the given environment variable is set.
> 
> I like this idea but have a bit of a security concern about the ability
> to set it to any file. If someone manages to set it then they can
> overwrite anything a process using the library can write to. 

That's not that serious a category of concern.  Environment variables
are not under control of untrusted agents.  FWIW, $DEBUGINFOD_CACHE is
considerably more dangerous in that regard (cache cleaning!).

> I rather it would just use stderr always when set since it is only
> meant as a human debugging device.

That default makes sense.  Making it configurable gives a way for a
larger app to still capture output (by having the client direct it to
a pipe file descriptor or something), but I'll just hardcode for now
STDERR_FILENO if the env var is set.


> >     Some larger usage experience (systemtap/kernels) indicates
> >     the default timeout is too short, so bumped it to 30s.

> My first thought is that we might need two timeouts. The original 5s
> timeout is a good inactivity timeout [...] But for larger data we
> might want a timeout for the total download time, maybe 30 seconds
> is too low for that. Given how large kernel debuginfo is it might
> take several minutes.

OK, redrafting $DEBUGINFOD_TIMEOUT as a two-part variable:

$DEBUGINFOD_TIMEOUT=x,y
 x - connection timeout, default 5
 y - optional, overall timeout, default unlimited

> [...]
> This seems to mean that if there is an error then the progress function
> is never called, is that intended? Also for CURLM_CALL_MULTI_PERFORM we
> continue/skip the progress function.

If we have an error outcome, there is no more progress to report, so
that should be OK.


> > +  close (fd); /* before the rmdir, otherwise it'll fail */
> >    (void) rmdir (target_cache_dir); /* nop if not empty */
> >    free(data);
> > -  close (fd);
> 
> This looks good. Just surprising. I assumed unlinking the file was
> enough.

Yeah, I had to see that for myself to believe it.


> The \r \n trick is nice.
> Just always using stderr would simplify this a bit.

OK.

> Also note that you can use dprintf to printf to a file descriptor. 

OK.


- FChE

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Frank Ch. Eigler]

Hi -

Pushed the following additional patch to fche/debuginfod-progress-env.
Hand-tested on a ginormous download with various length timeouts; hard
to test reliably within the elfutils testsuite (esp after removal of
that induced debuginfod-side wait).

commit beb09f4aa0634e89cf3ed513c66abec6bc65009f
Author: Frank Ch. Eigler <fche@redhat.com>
Date:   Fri Dec 13 11:51:37 2019 -0500

    debuginfod client: progress notification v2

diff --git a/debuginfod/debuginfod-client.c b/debuginfod/debuginfod-client.c
index 7a0a17519f42..55aab7b5b9a1 100644
--- a/debuginfod/debuginfod-client.c
+++ b/debuginfod/debuginfod-client.c
@@ -99,16 +99,16 @@ static const time_t cache_default_max_unused_age_s = 604800; /* 1 week */
 static const char *cache_default_name = ".debuginfod_client_cache";
 static const char *cache_path_envvar = DEBUGINFOD_CACHE_PATH_ENV_VAR;
 
-/* URLs of debuginfods, separated by url_delim.
-   This env var must be set for debuginfod-client to run.  */
+/* URLs of debuginfods, separated by url_delim. */
 static const char *server_urls_envvar = DEBUGINFOD_URLS_ENV_VAR;
 static const char *url_delim =  " ";
 static const char url_delim_char = ' ';
 
-/* Timeout for debuginfods, in seconds.
-   This env var must be set for debuginfod-client to run.  */
+/* Timeout for debuginfods, in seconds. */
 static const char *server_timeout_envvar = DEBUGINFOD_TIMEOUT_ENV_VAR;
-static int server_timeout = 30;
+static const long default_connect_timeout = 5;
+static const long default_transfer_timeout = -1; /* unlimited */
+
 
 /* Data associated with a particular CURL easy handle. Passed to
    the write callback.  */
@@ -399,8 +399,18 @@ debuginfod_query_server (debuginfod_client *c,
       goto out;
     }
 
-  if (getenv(server_timeout_envvar))
-    server_timeout = atoi (getenv(server_timeout_envvar));
+  long connect_timeout = default_connect_timeout;
+  long transfer_timeout = default_transfer_timeout;
+  const char* timeout_envvar = getenv(server_timeout_envvar);
+  if (timeout_envvar != NULL)
+    {
+      long ct, tt;
+      rc = sscanf(timeout_envvar, "%ld,%ld", &ct, &tt);
+      if (rc >= 1)
+        connect_timeout = ct;
+      if (rc >= 2)
+        transfer_timeout = tt;
+    }
 
   /* make a copy of the envvar so it can be safely modified.  */
   server_urls = strdup(urls_envvar);
@@ -492,7 +502,10 @@ debuginfod_query_server (debuginfod_client *c,
                        CURLOPT_WRITEFUNCTION,
                        debuginfod_write_callback);
       curl_easy_setopt(data[i].handle, CURLOPT_WRITEDATA, (void*)&data[i]);
-      curl_easy_setopt(data[i].handle, CURLOPT_TIMEOUT, (long) server_timeout);
+      if (connect_timeout >= 0)
+        curl_easy_setopt(data[i].handle, CURLOPT_CONNECTTIMEOUT, connect_timeout);
+      if (transfer_timeout >= 0)
+        curl_easy_setopt(data[i].handle, CURLOPT_TIMEOUT, transfer_timeout);
       curl_easy_setopt(data[i].handle, CURLOPT_FILETIME, (long) 1);
       curl_easy_setopt(data[i].handle, CURLOPT_FOLLOWLOCATION, (long) 1);
       curl_easy_setopt(data[i].handle, CURLOPT_FAILONERROR, (long) 1);
@@ -538,7 +551,7 @@ debuginfod_query_server (debuginfod_client *c,
         {
           loops ++;
           long pa = loops; /* default params for progress callback */
-          long pb = 0;
+          long pb = 0; /* transfer_timeout tempting, but loops != elapsed-time */
           if (target_handle) /* we've committed to a server; report its download progress */
             {
 #ifdef CURLINFO_SIZE_DOWNLOAD_T
@@ -557,6 +570,8 @@ debuginfod_query_server (debuginfod_client *c,
                 pa = (dl > LONG_MAX ? LONG_MAX : (long)dl);
 #endif
 
+              /* NB: If going through deflate-compressing proxies, this
+                 number is likely to be unavailable, so -1 may show. */
 #ifdef CURLINFO_CURLINFO_CONTENT_LENGTH_DOWNLOAD_T
               curl_off_t cl;
               curl_res = curl_easy_getinfo(target_handle,
@@ -693,25 +708,12 @@ default_progressfn (debuginfod_client *c, long a, long b)
 {
   (void) c;
 
-  int fd = open(getenv(DEBUGINFOD_PROGRESS_ENV_VAR),
-		O_APPEND|O_WRONLY|O_CREAT, 0666);
-  if (fd < 0)
-    goto out;
+  dprintf(STDERR_FILENO,
+          "Downloading from debuginfod %ld/%ld%s", a, b,
+          ((a == b) ? "\n" : "\r"));
+  /* XXX: include URL - stateful */
 
-  char *msg = NULL;
-  int rc = asprintf(&msg,
-		    "Downloading from debuginfod %ld/%ld%s", a, b,
-		    ((a == b) ? "\n" : "\r")); /* XXX: include URL - stateful */
-  if (rc < 0)
-    goto out1;
-
-  (void) write_retry(fd, msg, rc);
-  free (msg);
-
-  out1:
-    close (fd);
-  out:
-    return 0;
+  return 0;
 }
 
 
diff --git a/doc/debuginfod-find.1 b/doc/debuginfod-find.1
index 7f14e8c1411b..023acbb3b722 100644
--- a/doc/debuginfod-find.1
+++ b/doc/debuginfod-find.1
@@ -119,9 +119,13 @@ debuginfod instances.  Alternate URL prefixes are separated by space.
 
 .TP 21
 .B DEBUGINFOD_TIMEOUT
-This environment variable governs the timeout for each debuginfod HTTP
-connection.  A server that fails to respond within this many seconds
-is skipped.  The default is 30.
+This environment variable governs the timeouts for each debuginfod
+HTTP connection.  One or two comma-separated numbers may be given.
+The first is the number of seconds for the connection establishment
+(CURLOPT_CONNECTTIMEOUT), and the default is 5.  The second is the
+number of seconds for the transfer completion (CURLOPT_TIMEOUT), and
+the default is no timeout.  (Zero or negative also means "no
+timeout".)
 
 .TP 21
 .B DEBUGINFOD_CACHE_PATH
diff --git a/doc/debuginfod_find_debuginfo.3 b/doc/debuginfod_find_debuginfo.3
index 63766b33718d..ea8c61612924 100644
--- a/doc/debuginfod_find_debuginfo.3
+++ b/doc/debuginfod_find_debuginfo.3
@@ -163,9 +163,13 @@ debuginfod instances.  Alternate URL prefixes are separated by space.
 
 .TP 21
 .B DEBUGINFOD_TIMEOUT
-This environment variable governs the timeout for each debuginfod HTTP
-connection.  A server that fails to respond within this many seconds
-is skipped.  The default is 30.
+This environment variable governs the timeouts for each debuginfod
+HTTP connection.  One or two comma-separated numbers may be given.
+The first is the number of seconds for the connection establishment
+(CURLOPT_CONNECTTIMEOUT), and the default is 5.  The second is the
+number of seconds for the transfer completion (CURLOPT_TIMEOUT), and
+the default is no timeout.  (Zero or negative also means "no
+timeout".)
 
 .TP 21
 .B DEBUGINFOD_PROGRESS
diff --git a/tests/run-debuginfod-find.sh b/tests/run-debuginfod-find.sh
index be6d56575a3c..6ef30256749a 100755
--- a/tests/run-debuginfod-find.sh
+++ b/tests/run-debuginfod-find.sh
@@ -89,7 +89,7 @@ wait_ready $PORT1 'ready' 1
 export DEBUGINFOD_URLS=http://127.0.0.1:$PORT1/   # or without trailing /
 
 # Be patient when run on a busy machine things might take a bit.
-export DEBUGINFOD_TIMEOUT=10
+export DEBUGINFOD_TIMEOUT=1,10
 
 # We use -t0 and -g0 here to turn off time-based scanning & grooming.
 # For testing purposes, we just sic SIGUSR1 / SIGUSR2 at the process.
@@ -153,7 +153,7 @@ cmp $filename F/prog2
 cat vlog
 grep -q Progress vlog
 tempfiles vlog
-filename=`testrun env DEBUGINFOD_PROGRESS=vlog2 ${abs_top_builddir}/debuginfod/debuginfod-find executable $BUILDID2`
+filename=`testrun env DEBUGINFOD_PROGRESS=1 ${abs_top_builddir}/debuginfod/debuginfod-find executable $BUILDID2 2>vlog2`
 cmp $filename F/prog2
 cat vlog2
 grep -q Downloading vlog2

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Mark Wielaard]

Hi Frank,

On Thu, 2019-12-12 at 12:18 -0500, Frank Ch. Eigler wrote:
> > I like this idea but have a bit of a security concern about the ability
> > to set it to any file. If someone manages to set it then they can
> > overwrite anything a process using the library can write to. 
> 
> That's not that serious a category of concern.  Environment variables
> are not under control of untrusted agents.  FWIW, $DEBUGINFOD_CACHE is
> considerably more dangerous in that regard (cache cleaning!).

You have a way to make me even more scared of security issues than less
:)

It would actually be pretty bad if a user made the mistake to set
DEBUGINFOD_CACHE to e.g. their home directory by mistake.

Could we have some extra safeguard there? e.g. If the directory already
exist check whether it is completely empty or if it isn't empty it
contains a cache_clean_interval file? Or at least only delete files
that follow our creation pattern:
 <build-id-hexstring>/[debuginfo|executable|source]?

Doesn't need to be in your patch, but if you think something like that
isn't insane, the paranoid in me would like to add some extra
safeguards to not wipe out someones whole home dir by mistake.

> > I rather it would just use stderr always when set since it is only
> > meant as a human debugging device.
> 
> That default makes sense.  Making it configurable gives a way for a
> larger app to still capture output (by having the client direct it to
> a pipe file descriptor or something), but I'll just hardcode for now
> STDERR_FILENO if the env var is set.

That seems like a good default. Thanks.

> > >     Some larger usage experience (systemtap/kernels) indicates
> > >     the default timeout is too short, so bumped it to 30s.
> > My first thought is that we might need two timeouts. The original 5s
> > timeout is a good inactivity timeout [...] But for larger data we
> > might want a timeout for the total download time, maybe 30 seconds
> > is too low for that. Given how large kernel debuginfo is it might
> > take several minutes.
> 
> OK, redrafting $DEBUGINFOD_TIMEOUT as a two-part variable:
> 
> $DEBUGINFOD_TIMEOUT=x,y
>  x - connection timeout, default 5
>  y - optional, overall timeout, default unlimited

I would call the first progress_timeout since I think it is about
making progress, not just about connecting, but let me comment on the
actual patch. Maybe we actually need 3 values :)

> > [...]
> > This seems to mean that if there is an error then the progress function
> > is never called, is that intended? Also for CURLM_CALL_MULTI_PERFORM we
> > continue/skip the progress function.
> 
> If we have an error outcome, there is no more progress to report, so
> that should be OK.

Yeah, I guess if the first thing is an error, then no progress was ever
really made, so we just never report it. It is just a tiny change in
behavior. Although I doubt anybody would rely on the progress function
being called at least once.

Cheers,

Mark

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Mark Wielaard]

Hi Frank,

On Fri, 2019-12-13 at 11:57 -0500, Frank Ch. Eigler wrote:
> Pushed the following additional patch to fche/debuginfod-progress-env.
> Hand-tested on a ginormous download with various length timeouts; hard
> to test reliably within the elfutils testsuite (esp after removal of
> that induced debuginfod-side wait).

The code looks good in general, do note that if you rebase/squash to
onto master there is a slight conflict with the curl_res/curlm_res
fixlet. Since GCC10 isn't out yet, just yell if this gives you trouble
and I do/test it for you.

> +static const long default_connect_timeout = 5;
> +static const long default_transfer_timeout = -1; /* unlimited */
> +

I would call it default_progress_timeout, because...

> @@ -492,7 +502,10 @@ debuginfod_query_server (debuginfod_client *c,
>                         CURLOPT_WRITEFUNCTION,
>                         debuginfod_write_callback);
>        curl_easy_setopt(data[i].handle, CURLOPT_WRITEDATA, (void*)&data[i]);
> -      curl_easy_setopt(data[i].handle, CURLOPT_TIMEOUT, (long) server_timeout);
> +      if (connect_timeout >= 0)
> +        curl_easy_setopt(data[i].handle, CURLOPT_CONNECTTIMEOUT, connect_timeout);
> +      if (transfer_timeout >= 0)
> +        curl_easy_setopt(data[i].handle, CURLOPT_TIMEOUT, transfer_timeout);
>        curl_easy_setopt(data[i].handle, CURLOPT_FILETIME, (long) 1);
>        curl_easy_setopt(data[i].handle, CURLOPT_FOLLOWLOCATION, (long) 1);
>        curl_easy_setopt(data[i].handle, CURLOPT_FAILONERROR, (long) 1);

I would add something like:

  /* Make sure there is at least some progress,
     try to get at least 1K per progress timeout seconds.  */
  curl_easy_setopt(curl, CURLOPT_LOW_SPEED_TIME, 5 * 1024L);
  curl_easy_setopt(curl, CURLOPT_LOW_SPEED_LIMIT, progress_timeout);

The idea being that if we didn't at least get 1K per 5 seconds then the
connection is just so bad that it doesn't make sense to wait for it to
finish, since that will most likely be forever (or feel like it for the
user).

This might or might not be a separate timeout from the connect timeout,
but I think they are kind of the same thing.

Cheers,

Mark

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Frank Ch. Eigler]

Hi -

> > That's not that serious a category of concern.  Environment variables
> > are not under control of untrusted agents.  FWIW, $DEBUGINFOD_CACHE is
> > considerably more dangerous in that regard (cache cleaning!).
> 
> You have a way to make me even more scared of security issues than less
> :)
> 
> It would actually be pretty bad if a user made the mistake to set
> DEBUGINFOD_CACHE to e.g. their home directory by mistake.

Yeah, those bothering to override the default path have to be careful.

> Could we have some extra safeguard there? e.g. If the directory already
> exist check whether it is completely empty or if it isn't empty it
> contains a cache_clean_interval file? Or at least only delete files
> that follow our creation pattern:
>  <build-id-hexstring>/[debuginfo|executable|source]?

This sounds prudent.  Will work on that.


- FChE

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Frank Ch. Eigler]

Hi -

> The code looks good in general, do note that if you rebase/squash to
> onto master there is a slight conflict with the curl_res/curlm_res
> fixlet. Since GCC10 isn't out yet, just yell if this gives you trouble
> and I do/test it for you.

I'll figure it out and merge.


> [...]
> I would add something like:
> 
>   /* Make sure there is at least some progress,
>      try to get at least 1K per progress timeout seconds.  */
>   curl_easy_setopt(curl, CURLOPT_LOW_SPEED_TIME, 5 * 1024L);
>   curl_easy_setopt(curl, CURLOPT_LOW_SPEED_LIMIT, progress_timeout);
> 
> The idea being that if we didn't at least get 1K per 5 seconds then the
> connection is just so bad that it doesn't make sense to wait for it to
> finish, since that will most likely be forever (or feel like it for the
> user).

The problem with that is that, for a large download such as a kernel,
it can take almost a minute to just decompress the kernel-debuginfo
rpm far enough to start streaming the vmlinux file.  (In the presene
of caching somewhere in the http proxy tree, it gets much better the
second+ time.)  So any small default would be counterproductive to
e.g. systemtap users: they'd be forced to override this for basic
usage.

- FChE

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Mark Wielaard]

Hi Frank,

On Wed, 2019-12-18 at 19:47 -0500, Frank Ch. Eigler wrote:
> [...]
> > I would add something like:
> > 
> >   /* Make sure there is at least some progress,
> >      try to get at least 1K per progress timeout seconds.  */
> >   curl_easy_setopt(curl, CURLOPT_LOW_SPEED_TIME, 5 * 1024L);
> >   curl_easy_setopt(curl, CURLOPT_LOW_SPEED_LIMIT, progress_timeout);
> > 
> > The idea being that if we didn't at least get 1K per 5 seconds then the
> > connection is just so bad that it doesn't make sense to wait for it to
> > finish, since that will most likely be forever (or feel like it for the
> > user).

Note that the comment and the pseudo code are off. That "5 *" shouldn't
be there in the code.

> The problem with that is that, for a large download such as a kernel,
> it can take almost a minute to just decompress the kernel-debuginfo
> rpm far enough to start streaming the vmlinux file.  (In the presene
> of caching somewhere in the http proxy tree, it gets much better the
> second+ time.)  So any small default would be counterproductive to
> e.g. systemtap users: they'd be forced to override this for basic
> usage.

I can see how 5 seconds might be too low in such a case. But a whole
minute surprises me. But... indeed I tried myself and although not a
whole minute, it does seem to take more than 40 seconds. Most of it is
spend in rpm2cpio (I even tries a python implementation to compare).
There is of course some i/o delay involved. But the majority of the
time is cpu bound because the file needs to be decompressed.

Not that it would help us now, but I wonder if it would be worth it to
look at parallel compression/decompression to speed things up.

So 5 seconds no progress seems too low. But I still don't like infinite
as default. It seems unreasonable to let the user just wait
indefinitely when the connection seem stuck. How about saying something
like you need to get at least 450K in 90 seconds as default? I am
picking 90 seconds because that seems twice the worse case time to
decompress and that gives it about 45 seconds to provide ~10K/sec. But
if you are seeing 60 seconds as worse case we could pick something like
120 seconds or something.

But it should probably be a separate timeout from the connection
timeout, and maybe from the total timeout (or maybe replace it?). What
do you think?

Cheers,

Mark

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Frank Ch. Eigler]

Hi -


> There is of course some i/o delay involved. But the majority of the
> time is cpu bound because the file needs to be decompressed.
> Not that it would help us now, but I wonder if it would be worth it to
> look at parallel compression/decompression to speed things up.

Yeah, maybe.

> picking 90 seconds because that seems twice the worse case time to
> decompress and that gives it about 45 seconds to provide ~10K/sec. But
> if you are seeing 60 seconds as worse case we could pick something like
> 120 seconds or something.

That's a possibility.

> But it should probably be a separate timeout from the connection
> timeout, and maybe from the total timeout (or maybe replace
> it?). What do you think?

Yeah, a connection timeout per se is probably not really worth having.
A URL having unreasolvable hosts will fail immediately.  A reachable
http server that is fairly busy will connect, just take time.  The
only common cases a connection timeout would catch is a running http
server that is so overloaded that it can't even service its accept(4)
backlog, or a nonexistent one that has been tarpit/firewalled.  A
minimal progress timeout can subsume cases too.

OTOH, it's worth noting that these requests only take this kind of
time if they are being seriously serviced, i.e., "they are worth it".
Error cases fail relatively quickly.  It's the success cases - and
these huge vmlinux files - that take time.  And once the data starts
flowing - at all - the rest will follow as rapidly as the network
allows.

That suggests one timeout could be sufficient - the progress timeout
you the one you found - just not too short and not too fast.


- FChE

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Mark Wielaard]

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

Hi Frank,

On Sun, Dec 22, 2019 at 08:38:59PM -0500, Frank Ch. Eigler wrote:
> Yeah, a connection timeout per se is probably not really worth having.
> A URL having unreasolvable hosts will fail immediately.  A reachable
> http server that is fairly busy will connect, just take time.  The
> only common cases a connection timeout would catch is a running http
> server that is so overloaded that it can't even service its accept(4)
> backlog, or a nonexistent one that has been tarpit/firewalled.  A
> minimal progress timeout can subsume cases too.
> 
> OTOH, it's worth noting that these requests only take this kind of
> time if they are being seriously serviced, i.e., "they are worth it".
> Error cases fail relatively quickly.  It's the success cases - and
> these huge vmlinux files - that take time.  And once the data starts
> flowing - at all - the rest will follow as rapidly as the network
> allows.
> 
> That suggests one timeout could be sufficient - the progress timeout
> you the one you found - just not too short and not too fast.

How about the attached (untested) patch?

Cheers,

Mark

[-- Attachment #2: 0001-debuginfod-Use-DEBUGINFOD_TIMEOUT-as-seconds-to-get-.patch --]
[-- Type: text/x-diff, Size: 7887 bytes --]

From 9b90beee64299aca16df5b2322ae12f76d86e826 Mon Sep 17 00:00:00 2001
From: Mark Wielaard <mark@klomp.org>
Date: Thu, 2 Jan 2020 17:02:42 +0100
Subject: [PATCH] debuginfod: Use DEBUGINFOD_TIMEOUT as seconds to get at least
 100K.

Use just one timeout using CURLOPT_LOW_SPEED_TIME (default 60 seconds)
and CURLOPT_LOW_SPEED_LIMIT (100K).

Signed-off-by: Mark Wielaard <mark@klomp.org>
---
 debuginfod/ChangeLog            |  8 ++++++++
 debuginfod/debuginfod-client.c  | 30 +++++++++++++-----------------
 doc/ChangeLog                   |  7 +++++++
 doc/debuginfod-find.1           | 11 ++++-------
 doc/debuginfod.8                |  6 ++++--
 doc/debuginfod_find_debuginfo.3 | 11 ++++-------
 tests/ChangeLog                 |  4 ++++
 tests/run-debuginfod-find.sh    |  2 +-
 8 files changed, 45 insertions(+), 34 deletions(-)

diff --git a/debuginfod/ChangeLog b/debuginfod/ChangeLog
index 1582eba5..1f7a92b1 100644
--- a/debuginfod/ChangeLog
+++ b/debuginfod/ChangeLog
@@ -1,3 +1,11 @@
+2019-01-02  Mark Wielaard  <mark@klomp.org>
+
+	* debuginfod.cxx (default_connect_timeout): Removed.
+	(default_transfer_timeout): Removed.
+	(default_timeout): New. Default to 60 seconds.
+	(debuginfod_query_server): Parse server_timeout_envvar as one number.
+	Set as CURLOPT_LOW_SPEED_TIME, with CURL_OPT_LOW_SPEED_LIMITE as 100K.
+
 2019-12-22  Frank Ch. Eigler  <fche@redhat.com>
 
 	* debuginfod.cxx (*_rpm_*): Rename to *_archive_* throughout.
diff --git a/debuginfod/debuginfod-client.c b/debuginfod/debuginfod-client.c
index 9a4a0e0f..72a385c9 100644
--- a/debuginfod/debuginfod-client.c
+++ b/debuginfod/debuginfod-client.c
@@ -104,10 +104,9 @@ static const char *server_urls_envvar = DEBUGINFOD_URLS_ENV_VAR;
 static const char *url_delim =  " ";
 static const char url_delim_char = ' ';
 
-/* Timeout for debuginfods, in seconds. */
+/* Timeout for debuginfods, in seconds (to get at least 100K). */
 static const char *server_timeout_envvar = DEBUGINFOD_TIMEOUT_ENV_VAR;
-static const long default_connect_timeout = 5;
-static const long default_transfer_timeout = -1; /* unlimited */
+static const long default_timeout = 60;
 
 
 /* Data associated with a particular CURL easy handle. Passed to
@@ -401,18 +400,10 @@ debuginfod_query_server (debuginfod_client *c,
       return fd;
     }
 
-  long connect_timeout = default_connect_timeout;
-  long transfer_timeout = default_transfer_timeout;
+  long timeout = default_timeout;
   const char* timeout_envvar = getenv(server_timeout_envvar);
   if (timeout_envvar != NULL)
-    {
-      long ct, tt;
-      rc = sscanf(timeout_envvar, "%ld,%ld", &ct, &tt);
-      if (rc >= 1)
-        connect_timeout = ct;
-      if (rc >= 2)
-        transfer_timeout = tt;
-    }
+    timeout = atoi (timeout_envvar);
 
   /* make a copy of the envvar so it can be safely modified.  */
   server_urls = strdup(urls_envvar);
@@ -504,10 +495,15 @@ debuginfod_query_server (debuginfod_client *c,
                        CURLOPT_WRITEFUNCTION,
                        debuginfod_write_callback);
       curl_easy_setopt(data[i].handle, CURLOPT_WRITEDATA, (void*)&data[i]);
-      if (connect_timeout >= 0)
-        curl_easy_setopt(data[i].handle, CURLOPT_CONNECTTIMEOUT, connect_timeout);
-      if (transfer_timeout >= 0)
-        curl_easy_setopt(data[i].handle, CURLOPT_TIMEOUT, transfer_timeout);
+      if (timeout > 0)
+	{
+	  /* Make sure there is at least some progress,
+	     try to get at least 100K per timeout seconds.  */
+	  curl_easy_setopt (data[i].handle, CURLOPT_LOW_SPEED_TIME,
+			    timeout);
+	  curl_easy_setopt (data[i].handle, CURLOPT_LOW_SPEED_LIMIT,
+			    100 * 1024L);
+	}
       curl_easy_setopt(data[i].handle, CURLOPT_FILETIME, (long) 1);
       curl_easy_setopt(data[i].handle, CURLOPT_FOLLOWLOCATION, (long) 1);
       curl_easy_setopt(data[i].handle, CURLOPT_FAILONERROR, (long) 1);
diff --git a/doc/ChangeLog b/doc/ChangeLog
index 1422766d..57631c7d 100644
--- a/doc/ChangeLog
+++ b/doc/ChangeLog
@@ -1,3 +1,10 @@
+2020-01-02  Mark Wielaard  <mark@klomp.org>
+
+	* debuginfod.8 (DEBUGINFOD_TIMEOUT): Document as seconds to
+	provide 100K, default 60.
+	* debuginfod-find.1 (DEBUGINFOD_TIMEOUT): Likewise.
+	* debuginfod_find_debuginfo.3 (DEBUGINFOD_TIMEOUT): Likewise.
+
 2019-12-22  Frank Ch. Eigler  <fche@redhat.com
 
 	* debuginfod.8: Add -U (DEB) flag, generalize RPM to "archive".
diff --git a/doc/debuginfod-find.1 b/doc/debuginfod-find.1
index 023acbb3..3563e173 100644
--- a/doc/debuginfod-find.1
+++ b/doc/debuginfod-find.1
@@ -119,13 +119,10 @@ debuginfod instances.  Alternate URL prefixes are separated by space.
 
 .TP 21
 .B DEBUGINFOD_TIMEOUT
-This environment variable governs the timeouts for each debuginfod
-HTTP connection.  One or two comma-separated numbers may be given.
-The first is the number of seconds for the connection establishment
-(CURLOPT_CONNECTTIMEOUT), and the default is 5.  The second is the
-number of seconds for the transfer completion (CURLOPT_TIMEOUT), and
-the default is no timeout.  (Zero or negative also means "no
-timeout".)
+This environment variable governs the timeout for each debuginfod HTTP
+connection.  A server that fails to provide at least 100K of data
+within this many seconds is skipped. The default is 60 seconds.  (Zero
+or negative means "no timeout".)
 
 .TP 21
 .B DEBUGINFOD_CACHE_PATH
diff --git a/doc/debuginfod.8 b/doc/debuginfod.8
index 342f524c..47b9efd8 100644
--- a/doc/debuginfod.8
+++ b/doc/debuginfod.8
@@ -366,8 +366,10 @@ or indirectly - the results would be hilarious.
 .TP 21
 .B DEBUGINFOD_TIMEOUT
 This environment variable governs the timeout for each debuginfod HTTP
-connection.  A server that fails to respond within this many seconds
-is skipped.  The default is 5.
+connection.  A server that fails to provide at least 100K of data
+within this many seconds is skipped. The default is 60 seconds.  (Zero
+or negative means "no timeout".)
+
 
 .TP 21
 .B DEBUGINFOD_CACHE_PATH
diff --git a/doc/debuginfod_find_debuginfo.3 b/doc/debuginfod_find_debuginfo.3
index ea8c6161..e4507752 100644
--- a/doc/debuginfod_find_debuginfo.3
+++ b/doc/debuginfod_find_debuginfo.3
@@ -163,13 +163,10 @@ debuginfod instances.  Alternate URL prefixes are separated by space.
 
 .TP 21
 .B DEBUGINFOD_TIMEOUT
-This environment variable governs the timeouts for each debuginfod
-HTTP connection.  One or two comma-separated numbers may be given.
-The first is the number of seconds for the connection establishment
-(CURLOPT_CONNECTTIMEOUT), and the default is 5.  The second is the
-number of seconds for the transfer completion (CURLOPT_TIMEOUT), and
-the default is no timeout.  (Zero or negative also means "no
-timeout".)
+This environment variable governs the timeout for each debuginfod HTTP
+connection.  A server that fails to provide at least 100K of data
+within this many seconds is skipped. The default is 60 seconds.  (Zero
+or negative means "no timeout".)
 
 .TP 21
 .B DEBUGINFOD_PROGRESS
diff --git a/tests/ChangeLog b/tests/ChangeLog
index 02a8f75f..2638f63c 100644
--- a/tests/ChangeLog
+++ b/tests/ChangeLog
@@ -1,3 +1,7 @@
+2020-01-02  Mark Wielaard  <mark@klomp.org>
+
+	* run-debuginfod-find.sh: Set DEBUGINFOD_TIMEOUT to 10.
+
 2019-12-22  Frank Ch. Eigler  <fche@redhat.com>
 
 	* debuginfod-debs/*: New test files, based on
diff --git a/tests/run-debuginfod-find.sh b/tests/run-debuginfod-find.sh
index 90dafe00..4ab47a31 100755
--- a/tests/run-debuginfod-find.sh
+++ b/tests/run-debuginfod-find.sh
@@ -94,7 +94,7 @@ wait_ready $PORT1 'ready' 1
 export DEBUGINFOD_URLS=http://127.0.0.1:$PORT1/   # or without trailing /
 
 # Be patient when run on a busy machine things might take a bit.
-export DEBUGINFOD_TIMEOUT=1,10
+export DEBUGINFOD_TIMEOUT=10
 
 # We use -t0 and -g0 here to turn off time-based scanning & grooming.
 # For testing purposes, we just sic SIGUSR1 / SIGUSR2 at the process.
-- 
2.20.1

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Frank Ch. Eigler]

Hi -

> > That suggests one timeout could be sufficient - the progress timeout
> > you the one you found - just not too short and not too fast.
> 
> How about the attached (untested) patch?

That looks good, though I'd bump up the 60s -> 120s to give it a big
margin over already-observed latencies.

- FChE

Re: rfc/patch: debuginfod client $DEBUGINFOD_PROGRESS env var

[Mark Wielaard]

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

On Thu, 2020-01-02 at 11:44 -0500, Frank Ch. Eigler wrote:
> Hi -
> 
> > > That suggests one timeout could be sufficient - the progress
> > > timeout
> > > you the one you found - just not too short and not too fast.
> > 
> > How about the attached (untested) patch?

I finally tested it in various setups. Including your cool test server:
https://sourceware.org/ml/systemtap/2020-q1/msg00002.html


> That looks good, though I'd bump up the 60s -> 120s to give it a big
> margin over already-observed latencies.

Lets split the difference and make it 90s. That is more than twice the
worst delay I ever observed.

Pushed the attached.

Cheers,

Mark

[-- Attachment #2: 0001-debuginfod-Use-DEBUGINFOD_TIMEOUT-as-seconds-to-get-.patch --]
[-- Type: text/x-patch, Size: 7882 bytes --]

From b8d85ed024a745cff05e56c6337d95d654d5294a Mon Sep 17 00:00:00 2001
From: Mark Wielaard <mark@klomp.org>
Date: Thu, 2 Jan 2020 17:02:42 +0100
Subject: [PATCH] debuginfod: Use DEBUGINFOD_TIMEOUT as seconds to get at least
 100K.

Use just one timeout using CURLOPT_LOW_SPEED_TIME (default 90 seconds)
and CURLOPT_LOW_SPEED_LIMIT (100K).

Signed-off-by: Mark Wielaard <mark@klomp.org>
---
 debuginfod/ChangeLog            |  8 ++++++++
 debuginfod/debuginfod-client.c  | 30 +++++++++++++-----------------
 doc/ChangeLog                   |  7 +++++++
 doc/debuginfod-find.1           | 11 ++++-------
 doc/debuginfod.8                |  6 ++++--
 doc/debuginfod_find_debuginfo.3 | 11 ++++-------
 tests/ChangeLog                 |  4 ++++
 tests/run-debuginfod-find.sh    |  2 +-
 8 files changed, 45 insertions(+), 34 deletions(-)

diff --git a/debuginfod/ChangeLog b/debuginfod/ChangeLog
index 6cfb4e24..18778521 100644
--- a/debuginfod/ChangeLog
+++ b/debuginfod/ChangeLog
@@ -1,3 +1,11 @@
+2019-01-02  Mark Wielaard  <mark@klomp.org>
+
+	* debuginfod.cxx (default_connect_timeout): Removed.
+	(default_transfer_timeout): Removed.
+	(default_timeout): New. Default to 90 seconds.
+	(debuginfod_query_server): Parse server_timeout_envvar as one number.
+	Set as CURLOPT_LOW_SPEED_TIME, with CURL_OPT_LOW_SPEED_LIMITE as 100K.
+
 2020-01-09  Frank Ch. Eigler  <fche@redhat.com>
 
 	* debuginfod-client.c (add_extra_headers): New function,
diff --git a/debuginfod/debuginfod-client.c b/debuginfod/debuginfod-client.c
index 66ccb21a..e5a2e824 100644
--- a/debuginfod/debuginfod-client.c
+++ b/debuginfod/debuginfod-client.c
@@ -105,10 +105,9 @@ static const char *server_urls_envvar = DEBUGINFOD_URLS_ENV_VAR;
 static const char *url_delim =  " ";
 static const char url_delim_char = ' ';
 
-/* Timeout for debuginfods, in seconds. */
+/* Timeout for debuginfods, in seconds (to get at least 100K). */
 static const char *server_timeout_envvar = DEBUGINFOD_TIMEOUT_ENV_VAR;
-static const long default_connect_timeout = 5;
-static const long default_transfer_timeout = -1; /* unlimited */
+static const long default_timeout = 90;
 
 
 /* Data associated with a particular CURL easy handle. Passed to
@@ -483,18 +482,10 @@ debuginfod_query_server (debuginfod_client *c,
       return fd;
     }
 
-  long connect_timeout = default_connect_timeout;
-  long transfer_timeout = default_transfer_timeout;
+  long timeout = default_timeout;
   const char* timeout_envvar = getenv(server_timeout_envvar);
   if (timeout_envvar != NULL)
-    {
-      long ct, tt;
-      rc = sscanf(timeout_envvar, "%ld,%ld", &ct, &tt);
-      if (rc >= 1)
-        connect_timeout = ct;
-      if (rc >= 2)
-        transfer_timeout = tt;
-    }
+    timeout = atoi (timeout_envvar);
 
   /* make a copy of the envvar so it can be safely modified.  */
   server_urls = strdup(urls_envvar);
@@ -586,10 +577,15 @@ debuginfod_query_server (debuginfod_client *c,
                        CURLOPT_WRITEFUNCTION,
                        debuginfod_write_callback);
       curl_easy_setopt(data[i].handle, CURLOPT_WRITEDATA, (void*)&data[i]);
-      if (connect_timeout >= 0)
-        curl_easy_setopt(data[i].handle, CURLOPT_CONNECTTIMEOUT, connect_timeout);
-      if (transfer_timeout >= 0)
-        curl_easy_setopt(data[i].handle, CURLOPT_TIMEOUT, transfer_timeout);
+      if (timeout > 0)
+	{
+	  /* Make sure there is at least some progress,
+	     try to get at least 100K per timeout seconds.  */
+	  curl_easy_setopt (data[i].handle, CURLOPT_LOW_SPEED_TIME,
+			    timeout);
+	  curl_easy_setopt (data[i].handle, CURLOPT_LOW_SPEED_LIMIT,
+			    100 * 1024L);
+	}
       curl_easy_setopt(data[i].handle, CURLOPT_FILETIME, (long) 1);
       curl_easy_setopt(data[i].handle, CURLOPT_FOLLOWLOCATION, (long) 1);
       curl_easy_setopt(data[i].handle, CURLOPT_FAILONERROR, (long) 1);
diff --git a/doc/ChangeLog b/doc/ChangeLog
index 1422766d..b40a141b 100644
--- a/doc/ChangeLog
+++ b/doc/ChangeLog
@@ -1,3 +1,10 @@
+2020-01-02  Mark Wielaard  <mark@klomp.org>
+
+	* debuginfod.8 (DEBUGINFOD_TIMEOUT): Document as seconds to
+	provide 100K, default 90.
+	* debuginfod-find.1 (DEBUGINFOD_TIMEOUT): Likewise.
+	* debuginfod_find_debuginfo.3 (DEBUGINFOD_TIMEOUT): Likewise.
+
 2019-12-22  Frank Ch. Eigler  <fche@redhat.com
 
 	* debuginfod.8: Add -U (DEB) flag, generalize RPM to "archive".
diff --git a/doc/debuginfod-find.1 b/doc/debuginfod-find.1
index 023acbb3..e71ca29b 100644
--- a/doc/debuginfod-find.1
+++ b/doc/debuginfod-find.1
@@ -119,13 +119,10 @@ debuginfod instances.  Alternate URL prefixes are separated by space.
 
 .TP 21
 .B DEBUGINFOD_TIMEOUT
-This environment variable governs the timeouts for each debuginfod
-HTTP connection.  One or two comma-separated numbers may be given.
-The first is the number of seconds for the connection establishment
-(CURLOPT_CONNECTTIMEOUT), and the default is 5.  The second is the
-number of seconds for the transfer completion (CURLOPT_TIMEOUT), and
-the default is no timeout.  (Zero or negative also means "no
-timeout".)
+This environment variable governs the timeout for each debuginfod HTTP
+connection.  A server that fails to provide at least 100K of data
+within this many seconds is skipped. The default is 90 seconds.  (Zero
+or negative means "no timeout".)
 
 .TP 21
 .B DEBUGINFOD_CACHE_PATH
diff --git a/doc/debuginfod.8 b/doc/debuginfod.8
index 342f524c..6184bcce 100644
--- a/doc/debuginfod.8
+++ b/doc/debuginfod.8
@@ -366,8 +366,10 @@ or indirectly - the results would be hilarious.
 .TP 21
 .B DEBUGINFOD_TIMEOUT
 This environment variable governs the timeout for each debuginfod HTTP
-connection.  A server that fails to respond within this many seconds
-is skipped.  The default is 5.
+connection.  A server that fails to provide at least 100K of data
+within this many seconds is skipped. The default is 90 seconds.  (Zero
+or negative means "no timeout".)
+
 
 .TP 21
 .B DEBUGINFOD_CACHE_PATH
diff --git a/doc/debuginfod_find_debuginfo.3 b/doc/debuginfod_find_debuginfo.3
index ea8c6161..f6ea7a45 100644
--- a/doc/debuginfod_find_debuginfo.3
+++ b/doc/debuginfod_find_debuginfo.3
@@ -163,13 +163,10 @@ debuginfod instances.  Alternate URL prefixes are separated by space.
 
 .TP 21
 .B DEBUGINFOD_TIMEOUT
-This environment variable governs the timeouts for each debuginfod
-HTTP connection.  One or two comma-separated numbers may be given.
-The first is the number of seconds for the connection establishment
-(CURLOPT_CONNECTTIMEOUT), and the default is 5.  The second is the
-number of seconds for the transfer completion (CURLOPT_TIMEOUT), and
-the default is no timeout.  (Zero or negative also means "no
-timeout".)
+This environment variable governs the timeout for each debuginfod HTTP
+connection.  A server that fails to provide at least 100K of data
+within this many seconds is skipped. The default is 90 seconds.  (Zero
+or negative means "no timeout".)
 
 .TP 21
 .B DEBUGINFOD_PROGRESS
diff --git a/tests/ChangeLog b/tests/ChangeLog
index 02a8f75f..2638f63c 100644
--- a/tests/ChangeLog
+++ b/tests/ChangeLog
@@ -1,3 +1,7 @@
+2020-01-02  Mark Wielaard  <mark@klomp.org>
+
+	* run-debuginfod-find.sh: Set DEBUGINFOD_TIMEOUT to 10.
+
 2019-12-22  Frank Ch. Eigler  <fche@redhat.com>
 
 	* debuginfod-debs/*: New test files, based on
diff --git a/tests/run-debuginfod-find.sh b/tests/run-debuginfod-find.sh
index 90dafe00..4ab47a31 100755
--- a/tests/run-debuginfod-find.sh
+++ b/tests/run-debuginfod-find.sh
@@ -94,7 +94,7 @@ wait_ready $PORT1 'ready' 1
 export DEBUGINFOD_URLS=http://127.0.0.1:$PORT1/   # or without trailing /
 
 # Be patient when run on a busy machine things might take a bit.
-export DEBUGINFOD_TIMEOUT=1,10
+export DEBUGINFOD_TIMEOUT=10
 
 # We use -t0 and -g0 here to turn off time-based scanning & grooming.
 # For testing purposes, we just sic SIGUSR1 / SIGUSR2 at the process.
-- 
2.18.1