time_starttransfer reported wrong timestamp #11669
Comments
|
The libcurl docs for the time stamp is the canonical one. It describes this timer like this:
Does that not match what you see? |
|
Thank you for your update. Unfortunately, my answer is: No, it does not match what I saw for the case where the post request had a large payload. If time_starttransfer is indeed the time took from the start until the first byte of a server response is received, then it should report the timestamp of Packet 184 other than Packet 6. |
The time stamp is for measuring the first *received* byte Fixes #11669 Reported-by: JazJas on github
|
Try #11670 ! |
The time stamp is for measuring the first *received* byte Fixes #11669 Reported-by: JazJas on github
|
Thank you so much for your prompt actions. However, after patching, the time_starttransfer is still incorrectly set to the time when the first byte of the POST payload is sent to the server. In addition, the time_pretransfer should be set to the time when the last byte of the POST payload has been sent to the server so that the difference between time_starttransfer and time_pretransfer could be approximately used to determine the server response time. |
Are you sure you're running the version with the #11670 patch? I don't see how it stores any timestamp for that moment. Line 482 in 8a86ccf Any chance you can set a break-point to see how your
If so, that's a separate issue and I rather we keep that separate. One thing at a time. |
|
Thank you for your update. I am so sorry for my previous incorrect test result. I confirm that the time logged in TIMER_STARTTRANSFER is close to expected according to the analysis of packets captured by tcpdump. I am closing this issue. I will raise a separate issue for time_pretransfer. |
The time stamp is for measuring the first *received* byte Fixes curl#11669 Reported-by: JazJas on github Closes curl#11670
I did this
According to the man page below, the server response time can be: time_starttransfer - time_starttransfer
time_starttransfer: The time, in seconds, it took from the start until the first byte was just about to be transferred. This includes time_pretransfer and also the time the server needed to calculate the result.
However, curl (all versions) actually set the time_starttransfer incorrectly.
I used curl to send a large text file (134M) as a payload of a POST request to a HTTP server using the following syntax:
curl -s -w "%{time_pretransfer}\n%{time_starttransfer}\n" -o /dev/null --data-binary @file.txt --header @$headers_file $server_url --insecure
At the same time, tcpdump was used to capture all network packets.
When the curl command finished, I got:
time_pretransfer: 0.017484
time_starttransfer: 1.018670
However, when analyzing the captured packets, Time 0.017484 is roughly the point when the client sent the first packet of the request (ie Packet 4) and Time 1.018670 is when the client started sending the large post payload (ie Packet 6).
An in fact, the entire POST request is sent over the wire completely at Time 1.156250 (ie Packet 175), and the first packet of the response from the server is at Time 3.041776 (Packet 184).
I expected the following
First, the time_starttransfer is expected to be the timestamp of Packet 184. and the description of it should be made clear to something like: The time, in seconds, it took from the start until the first byte was just about to be transferred from the server. This includes time_pretransfer and also the time the server needed to calculate the result.
Second, the description of time_pretransfer needs to be made clearer. More details are given below:
According to my test results above, it looks like time_pretransfer is the time when the file transfer is just about to begin by a client. If this is indeed the intended result, then time_starttransfer should include time_pretransfer, the time the server needed to calculate the result, and the time the client needed to send the entire request. However, this will give users no idea how to calculate the server response time as the time the client needed to send the entire request is unknown.
Therefore:
If time_pretransfer is the time when the file transfer is just about to begin by a client:
If time_pretransfer is the time when the client complete sending the entire request:
curl/libcurl version
curl 8.2.1 (x86_64-pc-linux-gnu) libcurl/8.2.1 OpenSSL/3.0.9 zlib/1.2.13
Release-Date: 2023-07-26
Protocols: dict file ftp ftps gopher gophers http https imap imaps mqtt pop3 pop3s rtsp smb smbs smtp smtps telnet tftp
Features: alt-svc AsynchDNS HSTS HTTPS-proxy IPv6 Largefile libz NTLM NTLM_WB SSL threadsafe TLS-SRP UnixSockets
operating system
Linux kali 6.1.0-kali9-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.27-1kali1 (2023-05-12) x86_64 GNU/Linux
The text was updated successfully, but these errors were encountered: