rpms/nbdkit
7
0
Fork 0
Code Issues Pull Requests Releases Activity
6a6cb92d31
nbdkit/0012-curl-Add-D-curl.times-1-to-collect-time-statistics.patch
Richard W.M. Jones 6a6cb92d31 Backport nbdkit-curl-plugin "multi" interface support 
resolves: rhbz#2228131
Rebase to 1.34.2
resolves: rhbz#2168629
2023-08-01 15:36:49 +01:00

279 lines
9.3 KiB
Diff
Raw Blame History

From d8bbc2dd00eddd2c36a6a718f7e21e6e7d4f26e5 Mon Sep 17 00:00:00 2001
From: "Richard W.M. Jones" <rjones@redhat.com>
Date: Tue, 25 Jul 2023 21:45:31 +0100
Subject: [PATCH] curl: Add -D curl.times=1 to collect time statistics
(cherry picked from commit 68dddbeb584fb9385915846d259563f74338ffe8)
---
plugins/curl/Makefile.am | 1 +
plugins/curl/curl.c | 3 +
plugins/curl/curldefs.h | 13 +++
plugins/curl/nbdkit-curl-plugin.pod | 21 +++++
plugins/curl/pool.c | 2 +
plugins/curl/times.c | 130 ++++++++++++++++++++++++++++
6 files changed, 170 insertions(+)
create mode 100644 plugins/curl/times.c
diff --git a/plugins/curl/Makefile.am b/plugins/curl/Makefile.am
index 82c09582..f5f1cc1a 100644
--- a/plugins/curl/Makefile.am
+++ b/plugins/curl/Makefile.am
@@ -42,6 +42,7 @@ nbdkit_curl_plugin_la_SOURCES = \
curl.c \
pool.c \
scripts.c \
+ times.c \
$(top_srcdir)/include/nbdkit-plugin.h \
$(NULL)
diff --git a/plugins/curl/curl.c b/plugins/curl/curl.c
index 3557fd53..0d1fcfee 100644
--- a/plugins/curl/curl.c
+++ b/plugins/curl/curl.c
@@ -119,6 +119,7 @@ curl_unload (void)
curl_slist_free_all (resolves);
scripts_unload ();
unload_pool ();
+ display_times ();
curl_global_cleanup ();
}
@@ -639,6 +640,7 @@ curl_pread (void *handle, void *buf, uint32_t count, uint64_t offset)
display_curl_error (ch, r, "pread: curl_easy_perform");
return -1;
}
+ update_times (ch->c);
/* Could use curl_easy_getinfo here to obtain further information
* about the connection.
@@ -683,6 +685,7 @@ curl_pwrite (void *handle, const void *buf, uint32_t count, uint64_t offset)
display_curl_error (ch, r, "pwrite: curl_easy_perform");
return -1;
}
+ update_times (ch->c);
/* Could use curl_easy_getinfo here to obtain further information
* about the connection.
diff --git a/plugins/curl/curldefs.h b/plugins/curl/curldefs.h
index 4506f3e1..dd9791aa 100644
--- a/plugins/curl/curldefs.h
+++ b/plugins/curl/curldefs.h
@@ -44,6 +44,15 @@
#if CURL_AT_LEAST_VERSION (7, 55, 0)
#define HAVE_CURLINFO_CONTENT_LENGTH_DOWNLOAD_T
#endif
+#if CURL_AT_LEAST_VERSION (7, 61, 0)
+#define HAVE_CURLINFO_NAMELOOKUP_TIME_T
+#define HAVE_CURLINFO_CONNECT_TIME_T
+#define HAVE_CURLINFO_APPCONNECT_TIME_T
+#define HAVE_CURLINFO_PRETRANSFER_TIME_T
+#define HAVE_CURLINFO_STARTTRANSFER_TIME_T
+#define HAVE_CURLINFO_TOTAL_TIME_T
+#define HAVE_CURLINFO_REDIRECT_TIME_T
+#endif
#endif
extern const char *url;
@@ -131,6 +140,10 @@ extern void put_handle (struct curl_handle *ch);
extern int do_scripts (struct curl_handle *ch);
extern void scripts_unload (void);
+/* times.c */
+extern void update_times (CURL *c); /* called after every curl_easy_perform */
+extern void display_times (void);
+
/* Translate CURLcode to nbdkit_error. */
#define display_curl_error(ch, r, fs, ...) \
do { \
diff --git a/plugins/curl/nbdkit-curl-plugin.pod b/plugins/curl/nbdkit-curl-plugin.pod
index a7315047..0fd688ed 100644
--- a/plugins/curl/nbdkit-curl-plugin.pod
+++ b/plugins/curl/nbdkit-curl-plugin.pod
@@ -543,6 +543,27 @@ This prints out the headers and cookies generated by the
C<header-script> and C<cookie-script> options, which can be useful
when debugging these scripts.
+=item B<-D curl.times=1>
+
+This prints out additional information about the total time taken to
+do name resolution, connect to the remote server, etc. The
+information is printed in the debug output before nbdkit exits. The
+output will look like:
+
+ nbdkit: debug: times (-D curl.times=1):
+ nbdkit: debug: name resolution : 0.128442 s
+ nbdkit: debug: connection : 4.945213 s
+ nbdkit: debug: SSL negotiation : 4.291362 s
+ nbdkit: debug: pretransfer : 0.104137 s
+ nbdkit: debug: first byte received : 56.115269 s
+ nbdkit: debug: data transfer : 222.633831 s
+ nbdkit: debug: redirection time : 0.000000 s
+
+The cumulative time taken to perform each step is shown (summed across
+all HTTP connections). The redirection time is the total time taken
+doing HTTP redirections. For further information see
+L<curl_easy_getinfo(3)/TIMES>.
+
=item B<-D curl.verbose=1>
This enables very verbose curl debugging. See L<CURLOPT_VERBOSE(3)>.
diff --git a/plugins/curl/pool.c b/plugins/curl/pool.c
index f91cdf57..10f9011d 100644
--- a/plugins/curl/pool.c
+++ b/plugins/curl/pool.c
@@ -475,6 +475,7 @@ get_content_length_accept_range (struct curl_handle *ch)
display_curl_error (ch, r,
"problem doing HEAD request to fetch size of URL [%s]",
url);
+ update_times (ch->c);
/* Get the HTTP status code, if available. */
r = curl_easy_getinfo (ch->c, CURLINFO_RESPONSE_CODE, &code);
@@ -569,6 +570,7 @@ try_fallback_GET_method (struct curl_handle *ch)
curl_easy_setopt (ch->c, CURLOPT_WRITEFUNCTION, error_cb);
curl_easy_setopt (ch->c, CURLOPT_WRITEDATA, ch);
r = curl_easy_perform (ch->c);
+ update_times (ch->c);
/* We expect CURLE_WRITE_ERROR here, but CURLE_OK is possible too
* (eg if the remote has zero length). Other errors might happen
diff --git a/plugins/curl/times.c b/plugins/curl/times.c
new file mode 100644
index 00000000..8cc4cf27
--- /dev/null
+++ b/plugins/curl/times.c
@@ -0,0 +1,130 @@
+/* nbdkit
+ * Copyright Red Hat
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions are
+ * met:
+ *
+ * * Redistributions of source code must retain the above copyright
+ * notice, this list of conditions and the following disclaimer.
+ *
+ * * Redistributions in binary form must reproduce the above copyright
+ * notice, this list of conditions and the following disclaimer in the
+ * documentation and/or other materials provided with the distribution.
+ *
+ * * Neither the name of Red Hat nor the names of its contributors may be
+ * used to endorse or promote products derived from this software without
+ * specific prior written permission.
+ *
+ * THIS SOFTWARE IS PROVIDED BY RED HAT AND CONTRIBUTORS ''AS IS'' AND
+ * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO,
+ * THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A
+ * PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL RED HAT OR
+ * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+ * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+ * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF
+ * USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND
+ * ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
+ * OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT
+ * OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
+ * SUCH DAMAGE.
+ */
+
+#include <config.h>
+
+#include <stdio.h>
+#include <stdlib.h>
+#include <stdbool.h>
+#include <stdint.h>
+#include <inttypes.h>
+
+#include <curl/curl.h>
+
+#include <nbdkit-plugin.h>
+
+#include "array-size.h"
+
+#include "curldefs.h"
+
+/* Use '-D curl.times=1' to set. */
+NBDKIT_DLL_PUBLIC int curl_debug_times = 0;
+
+/* The cumulative times. */
+static struct {
+ bool cumulative;
+ const char *name;
+ CURLINFO info;
+ curl_off_t t;
+} times[] = {
+#ifdef HAVE_CURLINFO_NAMELOOKUP_TIME_T
+ { true, "name resolution", CURLINFO_NAMELOOKUP_TIME_T },
+#endif
+#ifdef HAVE_CURLINFO_CONNECT_TIME_T
+ { true, "connection", CURLINFO_CONNECT_TIME_T },
+#endif
+#ifdef HAVE_CURLINFO_APPCONNECT_TIME_T
+ { true, "SSL negotiation", CURLINFO_APPCONNECT_TIME_T },
+#endif
+#ifdef HAVE_CURLINFO_PRETRANSFER_TIME_T
+ { true, "pretransfer", CURLINFO_PRETRANSFER_TIME_T },
+#endif
+#ifdef HAVE_CURLINFO_STARTTRANSFER_TIME_T
+ { true, "first byte received", CURLINFO_STARTTRANSFER_TIME_T },
+#endif
+#ifdef HAVE_CURLINFO_TOTAL_TIME_T
+ { true, "data transfer", CURLINFO_TOTAL_TIME_T },
+#endif
+#ifdef HAVE_CURLINFO_REDIRECT_TIME_T
+ { false, "redirection time", CURLINFO_REDIRECT_TIME_T },
+#endif
+};
+
+/* This is called after every curl_easy_perform. If -D curl.times=1
+ * then we update the time counters. Refer to curl_easy_getinfo(3)
+ * section "TIMES".
+ */
+void
+update_times (CURL *c)
+{
+ size_t i;
+ CURLcode r;
+ curl_off_t t;
+
+ if (!curl_debug_times) return;
+
+ for (i = 0; i < ARRAY_SIZE (times); ++i) {
+ r = curl_easy_getinfo (c, times[i].info, &t);
+ if (r != CURLE_OK) {
+ nbdkit_debug ("curl_easy_getinfo: error getting time '%s': %s",
+ times[i].name, curl_easy_strerror (r));
+ continue;
+ }
+ if (curl_debug_verbose)
+ nbdkit_debug ("time '%s': %" PRIi64, times[i].name, (int64_t) t);
+ times[i].t += t;
+ }
+}
+
+/* Called when the plugin is unloaded. */
+void
+display_times (void)
+{
+ size_t i;
+ int64_t prev_t = 0, t, v;
+
+ if (!curl_debug_times) return;
+
+ nbdkit_debug ("times (-D curl.times=1):");
+ for (i = 0; i < ARRAY_SIZE (times); ++i) {
+ t = times[i].t; /* in microseconds */
+ if (times[i].cumulative)
+ v = t - prev_t;
+ else
+ v = t;
+ prev_t = t;
+
+ nbdkit_debug ("%-30s: %3" PRIi64 ".%06" PRIi64 " s",
+ times[i].name,
+ v / 1000000, v % 1000000);
+ }
+}
--
2.39.3
Reference in New Issue View Git Blame Copy Permalink