getinfo: add CURLINFO_POSTTRANSFER_TIME_T

Returns the time, in microseconds, from the start until the last byte is sent by libcurl (i.e. the request is sent off). Closes #14189
2024-07-15 11:52:50 +03:00 · 2024-07-15 11:52:50 +03:00 · 136504195a
--- a/.github/workflows/linux.yml
+++ b/.github/workflows/linux.yml
@ -169,6 +169,7 @@ jobs:
          - name: hyper
            install_steps: rust hyper valgrind
            configure: LDFLAGS="-Wl,-rpath,$HOME/hyper/target/debug" --with-openssl --with-hyper=$HOME/hyper --enable-debug --enable-websockets
+            tflags: '!500'
            singleuse: --unit

          - name: rustls
--- a/docs/cmdline-opts/write-out.md
+++ b/docs/cmdline-opts/write-out.md
@ -221,6 +221,10 @@ remote host (or proxy) was completed.
 The time, in seconds, it took from the start until the name resolving was
 completed.

+## `time_posttransfer`
+The time it took from the start until the last byte is sent by libcurl.
+In microseconds. (Added in 8.10.0)
+
 ## `time_pretransfer`
 The time, in seconds, it took from the start until the file transfer was just
 about to begin. This includes all pre-transfer commands and negotiations that
--- a/docs/libcurl/curl_easy_getinfo.md
+++ b/docs/libcurl/curl_easy_getinfo.md
@ -180,6 +180,11 @@ See CURLINFO_NUM_CONNECTS(3)

 The errno from the last failure to connect. See CURLINFO_OS_ERRNO(3)

+## CURLINFO_POSTTRANSFER_TIME_T
+
+The time it took from the start until the last byte is sent by libcurl.
+In microseconds. (Added in 8.10.0) See CURLINFO_POSTTRANSFER_TIME_T(3)
+
 ## CURLINFO_PRETRANSFER_TIME

 The time it took from the start until the file transfer is just about to
@ -375,15 +380,17 @@ An overview of the time values available from curl_easy_getinfo(3)
        |--|--|--CONNECT
        |--|--|--|--APPCONNECT
        |--|--|--|--|--PRETRANSFER
-        |--|--|--|--|--|--STARTTRANSFER
-        |--|--|--|--|--|--|--TOTAL
-        |--|--|--|--|--|--|--REDIRECT
+        |--|--|--|--|--|--POSTTRANSFER
+        |--|--|--|--|--|--|--STARTTRANSFER
+        |--|--|--|--|--|--|--|--TOTAL
+        |--|--|--|--|--|--|--|--REDIRECT


 CURLINFO_QUEUE_TIME_T(3), CURLINFO_NAMELOOKUP_TIME_T(3),
 CURLINFO_CONNECT_TIME_T(3), CURLINFO_APPCONNECT_TIME_T(3),
- CURLINFO_PRETRANSFER_TIME_T(3), CURLINFO_STARTTRANSFER_TIME_T(3),
- CURLINFO_TOTAL_TIME_T(3), CURLINFO_REDIRECT_TIME_T(3)
+ CURLINFO_PRETRANSFER_TIME_T(3), CURLINFO_POSTTRANSFER_TIME_T(3),
+ CURLINFO_STARTTRANSFER_TIME_T(3), CURLINFO_TOTAL_TIME_T(3),
+ CURLINFO_REDIRECT_TIME_T(3)

 # %PROTOCOLS%

--- a/docs/libcurl/opts/CURLINFO_POSTTRANSFER_TIME_T.md
+++ b/docs/libcurl/opts/CURLINFO_POSTTRANSFER_TIME_T.md
@ -0,0 +1,69 @@
+---
+c: Copyright (C) Daniel Stenberg, <daniel@haxx.se>, et al.
+SPDX-License-Identifier: curl
+Title: CURLINFO_POSTTRANSFER_TIME_T
+Section: 3
+Source: libcurl
+See-also:
+  - CURLINFO_PRETRANSFER_TIME_T (3)
+  - CURLOPT_TIMEOUT (3)
+  - curl_easy_getinfo (3)
+  - curl_easy_setopt (3)
+Protocol:
+  - All
+Added-in: 8.10.0
+---
+
+# NAME
+
+CURLINFO_POSTTRANSFER_TIME_T - get the time until the last byte is sent
+
+# SYNOPSIS
+
+~~~c
+#include <curl/curl.h>
+
+CURLcode curl_easy_getinfo(CURL *handle, CURLINFO_POSTTRANSFER_TIME_T,
+                           curl_off_t *timep);
+~~~
+
+# DESCRIPTION
+
+Pass a pointer to a curl_off_t to receive the time, in microseconds,
+it took from the start until the last byte is sent by libcurl.
+
+When a redirect is followed, the time from each request is added together.
+
+See also the TIMES overview in the curl_easy_getinfo(3) man page.
+
+# %PROTOCOLS%
+
+# EXAMPLE
+
+~~~c
+int main(void)
+{
+  CURL *curl = curl_easy_init();
+  if(curl) {
+    CURLcode res;
+    curl_easy_setopt(curl, CURLOPT_URL, "https://example.com");
+    res = curl_easy_perform(curl);
+    if(CURLE_OK == res) {
+      curl_off_t posttransfer;
+      res = curl_easy_getinfo(curl, CURLINFO_POSTTRANSFER_TIME_T, &posttransfer);
+      if(CURLE_OK == res) {
+        printf("Request sent after: %" CURL_FORMAT_CURL_OFF_T ".%06ld us", posttransfer / 1000000,
+               (long)(posttransfer % 1000000));
+      }
+    }
+    /* always cleanup */
+    curl_easy_cleanup(curl);
+  }
+}
+~~~
+
+# %AVAILABILITY%
+
+# RETURN VALUE
+
+Returns CURLE_OK if the option is supported, and CURLE_UNKNOWN_OPTION if not.
--- a/docs/libcurl/opts/Makefile.inc
+++ b/docs/libcurl/opts/Makefile.inc
@ -58,6 +58,7 @@ man_MANS =                                      \
  CURLINFO_OS_ERRNO.3                           \
  CURLINFO_PRETRANSFER_TIME.3                   \
  CURLINFO_PRETRANSFER_TIME_T.3                 \
+  CURLINFO_POSTTRANSFER_TIME_T.3                \
  CURLINFO_PRIMARY_IP.3                         \
  CURLINFO_PRIMARY_PORT.3                       \
  CURLINFO_PRIVATE.3                            \
--- a/docs/libcurl/symbols-in-versions
+++ b/docs/libcurl/symbols-in-versions
@ -462,6 +462,7 @@ CURLINFO_OFF_T                  7.55.0
 CURLINFO_OS_ERRNO               7.12.2
 CURLINFO_PRETRANSFER_TIME       7.4.1
 CURLINFO_PRETRANSFER_TIME_T     7.61.0
+CURLINFO_POSTTRANSFER_TIME_T    8.10.0
 CURLINFO_PRIMARY_IP             7.19.0
 CURLINFO_PRIMARY_PORT           7.21.0
 CURLINFO_PRIVATE                7.10.3
--- a/include/curl/curl.h
+++ b/include/curl/curl.h
@ -2953,7 +2953,8 @@ typedef enum {
  CURLINFO_CONN_ID          = CURLINFO_OFF_T + 64,
  CURLINFO_QUEUE_TIME_T     = CURLINFO_OFF_T + 65,
  CURLINFO_USED_PROXY       = CURLINFO_LONG + 66,
-  CURLINFO_LASTONE          = 66
+  CURLINFO_POSTTRANSFER_TIME_T = CURLINFO_OFF_T + 67,
+  CURLINFO_LASTONE          = 67
 } CURLINFO;

 /* CURLINFO_RESPONSE_CODE is the new name for the option previously known as
--- a/lib/getinfo.c
+++ b/lib/getinfo.c
@ -53,6 +53,7 @@ CURLcode Curl_initinfo(struct Curl_easy *data)
  pro->t_connect = 0;
  pro->t_appconnect = 0;
  pro->t_pretransfer = 0;
+  pro->t_posttransfer = 0;
  pro->t_starttransfer = 0;
  pro->timespent = 0;
  pro->t_redirect = 0;
@ -368,6 +369,7 @@ static CURLcode getinfo_offt(struct Curl_easy *data, CURLINFO info,
    case CURLINFO_CONNECT_TIME_T:
    case CURLINFO_APPCONNECT_TIME_T:
    case CURLINFO_PRETRANSFER_TIME_T:
+    case CURLINFO_POSTTRANSFER_TIME_T:
    case CURLINFO_STARTTRANSFER_TIME_T:
    case CURLINFO_REDIRECT_TIME_T:
    case CURLINFO_SPEED_DOWNLOAD_T:
@ -418,6 +420,9 @@ static CURLcode getinfo_offt(struct Curl_easy *data, CURLINFO info,
  case CURLINFO_PRETRANSFER_TIME_T:
    *param_offt = data->progress.t_pretransfer;
    break;
+  case CURLINFO_POSTTRANSFER_TIME_T:
+    *param_offt = data->progress.t_posttransfer;
+    break;
  case CURLINFO_STARTTRANSFER_TIME_T:
    *param_offt = data->progress.t_starttransfer;
    break;
--- a/lib/progress.c
+++ b/lib/progress.c
@ -217,7 +217,7 @@ void Curl_pgrsTimeWas(struct Curl_easy *data, timerid timer,
      break;
    }
  case TIMER_POSTRANSFER:
-    /* this is the normal end-of-transfer thing */
+    delta = &data->progress.t_posttransfer;
    break;
  case TIMER_REDIRECT:
    data->progress.t_redirect = Curl_timediff_us(timestamp,
--- a/lib/request.c
+++ b/lib/request.c
@ -258,6 +258,7 @@ CURLcode Curl_req_set_upload_done(struct Curl_easy *data)
  data->req.upload_done = TRUE;
  data->req.keepon &= ~(KEEP_SEND|KEEP_SEND_TIMED); /* we are done sending */

+  Curl_pgrsTime(data, TIMER_POSTRANSFER);
  Curl_creader_done(data, data->req.upload_aborted);

  if(data->req.upload_aborted) {
--- a/lib/urldata.h
+++ b/lib/urldata.h
@ -1091,6 +1091,7 @@ struct Progress {
  timediff_t t_connect;
  timediff_t t_appconnect;
  timediff_t t_pretransfer;
+  timediff_t t_posttransfer;
  timediff_t t_starttransfer;
  timediff_t t_redirect;

--- a/src/tool_writeout.c
+++ b/src/tool_writeout.c
@ -119,6 +119,8 @@ static const struct writeoutvar variables[] = {
  {"time_connect", VAR_CONNECT_TIME, CURLINFO_CONNECT_TIME_T, writeTime},
  {"time_namelookup", VAR_NAMELOOKUP_TIME, CURLINFO_NAMELOOKUP_TIME_T,
   writeTime},
+  {"time_posttransfer", VAR_POSTTRANSFER_TIME, CURLINFO_POSTTRANSFER_TIME_T,
+   writeTime},
  {"time_pretransfer", VAR_PRETRANSFER_TIME, CURLINFO_PRETRANSFER_TIME_T,
   writeTime},
  {"time_redirect", VAR_REDIRECT_TIME, CURLINFO_REDIRECT_TIME_T, writeTime},
--- a/src/tool_writeout.h
+++ b/src/tool_writeout.h
@ -77,6 +77,7 @@ typedef enum {
  VAR_NUM_RETRY,
  VAR_ONERROR,
  VAR_PRETRANSFER_TIME,
+  VAR_POSTTRANSFER_TIME,
  VAR_PRIMARY_IP,
  VAR_PRIMARY_PORT,
  VAR_PROXY_SSL_VERIFY_RESULT,
--- a/tests/data/test1541
+++ b/tests/data/test1541
@ -36,6 +36,7 @@ Transfer-Encoding: chunked
 datad474
 CURLINFO_CONNECT_TIME_T on done is OK
 CURLINFO_PRETRANSFER_TIME_T on done is OK
+CURLINFO_POSTTRANSFER_TIME_T on done is OK
 CURLINFO_STARTTRANSFER_TIME_T on done is OK
 CURLINFO_APPCONNECT_TIME_T on done is OK
 CURLINFO_SPEED_DOWNLOAD_T on done is OK
--- a/tests/data/test970
+++ b/tests/data/test970
@ -59,7 +59,7 @@ Accept: */*

 </protocol>
 <stdout nonewline="yes">
-{"certs":"","conn_id":0,"content_type":"text/html","errormsg":null,"exitcode":0,"filename_effective":"%LOGDIR/out%TESTNUMBER","ftp_entry_path":null,"http_code":200,"http_connect":0,"http_version":"1.1","local_ip":"127.0.0.1","local_port":13,"method":"GET","num_certs":0,"num_connects":1,"num_headers":9,"num_redirects":0,"num_retries":0,"proxy_ssl_verify_result":0,"proxy_used":0,"redirect_url":null,"referer":null,"remote_ip":"%HOSTIP","remote_port":%HTTPPORT,"response_code":200,"scheme":"http","size_download":445,"size_header":4019,"size_request":4019,"size_upload":0,"speed_download":13,"speed_upload":13,"ssl_verify_result":0,"time_appconnect":0.000013,"time_connect":0.000013,"time_namelookup":0.000013,"time_pretransfer":0.000013,"time_redirect":0.000013,"time_starttransfer":0.000013,"time_total":0.000013,"url":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","url.fragment":null,"url.host":"127.0.0.1","url.options":null,"url.password":null,"url.path":"/%TESTNUMBER","url.port":"%HTTPPORT","url.query":null,"url.scheme":"http","url.user":null,"url.zoneid":null,"url_effective":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","urle.fragment":null,"urle.host":"127.0.0.1","urle.options":null,"urle.password":null,"urle.path":"/%TESTNUMBER","urle.port":"%HTTPPORT","urle.query":null,"urle.scheme":"http","urle.user":null,"urle.zoneid":null,"urlnum":0,"xfer_id":0,"curl_version":"curl-unit-test-fake-version"}
+{"certs":"","conn_id":0,"content_type":"text/html","errormsg":null,"exitcode":0,"filename_effective":"%LOGDIR/out%TESTNUMBER","ftp_entry_path":null,"http_code":200,"http_connect":0,"http_version":"1.1","local_ip":"127.0.0.1","local_port":13,"method":"GET","num_certs":0,"num_connects":1,"num_headers":9,"num_redirects":0,"num_retries":0,"proxy_ssl_verify_result":0,"proxy_used":0,"redirect_url":null,"referer":null,"remote_ip":"%HOSTIP","remote_port":%HTTPPORT,"response_code":200,"scheme":"http","size_download":445,"size_header":4019,"size_request":4019,"size_upload":0,"speed_download":13,"speed_upload":13,"ssl_verify_result":0,"time_appconnect":0.000013,"time_connect":0.000013,"time_namelookup":0.000013,"time_posttransfer":0.000013,"time_pretransfer":0.000013,"time_redirect":0.000013,"time_starttransfer":0.000013,"time_total":0.000013,"url":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","url.fragment":null,"url.host":"127.0.0.1","url.options":null,"url.password":null,"url.path":"/%TESTNUMBER","url.port":"%HTTPPORT","url.query":null,"url.scheme":"http","url.user":null,"url.zoneid":null,"url_effective":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","urle.fragment":null,"urle.host":"127.0.0.1","urle.options":null,"urle.password":null,"urle.path":"/%TESTNUMBER","urle.port":"%HTTPPORT","urle.query":null,"urle.scheme":"http","urle.user":null,"urle.zoneid":null,"urlnum":0,"xfer_id":0,"curl_version":"curl-unit-test-fake-version"}
 </stdout>
 </verify>
 </testcase>
--- a/tests/data/test972
+++ b/tests/data/test972
@ -60,7 +60,7 @@ Accept: */*

 </protocol>
 <stdout mode="text">
-{"certs":"","conn_id":0,"content_type":"text/html","errormsg":null,"exitcode":0,"filename_effective":"%LOGDIR/out%TESTNUMBER","ftp_entry_path":null,"http_code":200,"http_connect":0,"http_version":"1.1","local_ip":"127.0.0.1","local_port":13,"method":"GET","num_certs":0,"num_connects":1,"num_headers":9,"num_redirects":0,"num_retries":0,"proxy_ssl_verify_result":0,"proxy_used":0,"redirect_url":null,"referer":null,"remote_ip":"%HOSTIP","remote_port":%HTTPPORT,"response_code":200,"scheme":"http","size_download":445,"size_header":4019,"size_request":4019,"size_upload":0,"speed_download":13,"speed_upload":13,"ssl_verify_result":0,"time_appconnect":0.000013,"time_connect":0.000013,"time_namelookup":0.000013,"time_pretransfer":0.000013,"time_redirect":0.000013,"time_starttransfer":0.000013,"time_total":0.000013,"url":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","url.fragment":null,"url.host":"127.0.0.1","url.options":null,"url.password":null,"url.path":"/%TESTNUMBER","url.port":"%HTTPPORT","url.query":null,"url.scheme":"http","url.user":null,"url.zoneid":null,"url_effective":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","urle.fragment":null,"urle.host":"127.0.0.1","urle.options":null,"urle.password":null,"urle.path":"/%TESTNUMBER","urle.port":"%HTTPPORT","urle.query":null,"urle.scheme":"http","urle.user":null,"urle.zoneid":null,"urlnum":0,"xfer_id":0,"curl_version":"curl-unit-test-fake-version"}
+{"certs":"","conn_id":0,"content_type":"text/html","errormsg":null,"exitcode":0,"filename_effective":"%LOGDIR/out%TESTNUMBER","ftp_entry_path":null,"http_code":200,"http_connect":0,"http_version":"1.1","local_ip":"127.0.0.1","local_port":13,"method":"GET","num_certs":0,"num_connects":1,"num_headers":9,"num_redirects":0,"num_retries":0,"proxy_ssl_verify_result":0,"proxy_used":0,"redirect_url":null,"referer":null,"remote_ip":"%HOSTIP","remote_port":%HTTPPORT,"response_code":200,"scheme":"http","size_download":445,"size_header":4019,"size_request":4019,"size_upload":0,"speed_download":13,"speed_upload":13,"ssl_verify_result":0,"time_appconnect":0.000013,"time_connect":0.000013,"time_namelookup":0.000013,"time_posttransfer":0.000013,"time_pretransfer":0.000013,"time_redirect":0.000013,"time_starttransfer":0.000013,"time_total":0.000013,"url":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","url.fragment":null,"url.host":"127.0.0.1","url.options":null,"url.password":null,"url.path":"/%TESTNUMBER","url.port":"%HTTPPORT","url.query":null,"url.scheme":"http","url.user":null,"url.zoneid":null,"url_effective":"http://%HOSTIP:%HTTPPORT/%TESTNUMBER","urle.fragment":null,"urle.host":"127.0.0.1","urle.options":null,"urle.password":null,"urle.path":"/%TESTNUMBER","urle.port":"%HTTPPORT","urle.query":null,"urle.scheme":"http","urle.user":null,"urle.zoneid":null,"urlnum":0,"xfer_id":0,"curl_version":"curl-unit-test-fake-version"}
 </stdout>
 </verify>
 </testcase>
--- a/tests/libtest/lib1541.c
+++ b/tests/libtest/lib1541.c
@ -137,6 +137,7 @@ CURLcode test(char *URL)

  check_time(curls, KN(CURLINFO_CONNECT_TIME_T), "done");
  check_time(curls, KN(CURLINFO_PRETRANSFER_TIME_T), "done");
+  check_time(curls, KN(CURLINFO_POSTTRANSFER_TIME_T), "done");
  check_time(curls, KN(CURLINFO_STARTTRANSFER_TIME_T), "done");
  /* no SSL, must be 0 */
  check_time0(curls, KN(CURLINFO_APPCONNECT_TIME_T), "done");
--- a/tests/libtest/lib500.c
+++ b/tests/libtest/lib500.c
@ -101,6 +101,7 @@ CURLcode test(char *URL)
        curl_off_t time_namelookup;
        curl_off_t time_connect;
        curl_off_t time_pretransfer;
+        curl_off_t time_posttransfer;
        curl_off_t time_starttransfer;
        curl_off_t time_total;
        fprintf(moo, "IP %s\n", ipstr);
@ -108,6 +109,8 @@ CURLcode test(char *URL)
        curl_easy_getinfo(curl, CURLINFO_CONNECT_TIME_T, &time_connect);
        curl_easy_getinfo(curl, CURLINFO_PRETRANSFER_TIME_T,
                          &time_pretransfer);
+        curl_easy_getinfo(curl, CURLINFO_POSTTRANSFER_TIME_T,
+                          &time_posttransfer);
        curl_easy_getinfo(curl, CURLINFO_STARTTRANSFER_TIME_T,
                          &time_starttransfer);
        curl_easy_getinfo(curl, CURLINFO_TOTAL_TIME_T, &time_total);
@ -128,6 +131,14 @@ CURLcode test(char *URL)
                  (time_pretransfer / 1000000),
                  (long)(time_pretransfer % 1000000));
        }
+        if(time_pretransfer > time_posttransfer) {
+          fprintf(moo, "pretransfer vs posttransfer: %" CURL_FORMAT_CURL_OFF_T
+                  ".%06ld %" CURL_FORMAT_CURL_OFF_T ".%06ld\n",
+                  (time_pretransfer / 1000000),
+                  (long)(time_pretransfer % 1000000),
+                  (time_posttransfer / 1000000),
+                  (long)(time_posttransfer % 1000000));
+        }
        if(time_pretransfer > time_starttransfer) {
          fprintf(moo, "pretransfer vs starttransfer: %" CURL_FORMAT_CURL_OFF_T
                  ".%06ld %" CURL_FORMAT_CURL_OFF_T ".%06ld\n",
@ -143,6 +154,13 @@ CURLcode test(char *URL)
                  (long)(time_starttransfer % 1000000),
                  (time_total / 1000000), (long)(time_total % 1000000));
        }
+        if(time_posttransfer > time_total) {
+          fprintf(moo, "posttransfer vs total: %" CURL_FORMAT_CURL_OFF_T
+                  ".%06ld %" CURL_FORMAT_CURL_OFF_T ".%06ld\n",
+                  (time_posttransfer / 1000000),
+                  (long)(time_posttransfer % 1000000),
+                  (time_total / 1000000), (long)(time_total % 1000000));
+        }

        fclose(moo);
      }