romenskiy2012/curl
1
0
Fork 0
mirror of https://github.com/curl/curl.git synced 2026-07-28 02:33:06 +03:00
Code Issues Projects Releases Packages Wiki Activity

lib: timer stats improvements

Browse source 
* move the TIMER_POSTQUEUE to the time a connection is chosen,
  so that TIMER_NAMELOOKUP always happens afterwards
* client writer: do not trigger TIMER_STARTTRANSFER on CLIENTWRITE_INFO
  as ftp and other pingpong protocols write that before starting anything
  that is the tranfer itself
* Elimnating debug trancing of "closed stream/connection - bailing"
  as confusing, as connection is not really closed on most cases.
* Setting 'data->req.upload_done` correctly, so that no "abort upload"
  is happening at the end of a perfectly fine download.
* Adding test cases with up-/download of 0-length files.
* pytest: add a "timeline" of timer value checks to Resulst in curl.py,
  so that this can be used in several test cases, replacing the local
  stuff in test_16
* add timeline checks to ftp test cases

Closes #19269
This commit is contained in:
Stefan Eissing 2025-11-25 10:00:23 +01:00 • committed by Daniel Stenberg
parent fc09a2da4a
commit 208a6aebf2
No known key found for this signature in database
GPG key ID: 5CC908FDB71E12C2
14 changed files with 141 additions and 82 deletions
Download patch file Download diff file Expand all files Collapse all files

13
lib/cfilters.c
View file

@ -63,8 +63,8 @@ CURLcode Curl_cf_def_shutdown(struct Curl_cfilter *cf,
return CURLE_OK;
}
static void conn_report_connect_stats(struct Curl_easy *data,
struct connectdata *conn);
static void conn_report_connect_stats(struct Curl_cfilter *cf,
struct Curl_easy *data);
CURLcode Curl_cf_def_adjust_pollset(struct Curl_cfilter *cf,
struct Curl_easy *data,
@ -508,7 +508,7 @@ CURLcode Curl_conn_connect(struct Curl_easy *data,
* persist information at the connection. E.g. cf-socket sets the
* socket and ip related information. */
cf_cntrl_update_info(data, data->conn);
conn_report_connect_stats(data, data->conn);
conn_report_connect_stats(cf, data);
data->conn->keepalive = curlx_now();
#ifndef CURL_DISABLE_VERBOSE_STRINGS
result = cf_verboseconnect(data, cf);
@ -518,7 +518,7 @@ CURLcode Curl_conn_connect(struct Curl_easy *data,
else if(result) {
CURL_TRC_CF(data, cf, "Curl_conn_connect(), filter returned %d",
result);
conn_report_connect_stats(data, data->conn);
conn_report_connect_stats(cf, data);
goto out;
}
@ -1008,10 +1008,9 @@ static void cf_cntrl_update_info(struct Curl_easy *data,
/**
* Update connection statistics
*/
static void conn_report_connect_stats(struct Curl_easy *data,
struct connectdata *conn)
static void conn_report_connect_stats(struct Curl_cfilter *cf,
struct Curl_easy *data)
{
struct Curl_cfilter *cf = conn->cfilter[FIRSTSOCKET];
if(cf) {
struct curltime connected;
struct curltime appconnected;

2
lib/multi.c
View file

@ -2337,7 +2337,7 @@ static CURLMcode state_connect(struct Curl_multi *multi,
process_pending_handles(data->multi);
if(!result) {
*nowp = Curl_pgrsTime(data, TIMER_POSTQUEUE);
*nowp = curlx_now();
if(async)
/* We are now waiting for an asynchronous name lookup */
multistate(data, MSTATE_RESOLVING);

10
lib/request.c
View file

@ -393,6 +393,11 @@ CURLcode Curl_req_send(struct Curl_easy *data, struct dynbuf *req,
return result;
buf += nwritten;
blen -= nwritten;
if(!blen) {
result = req_set_upload_done(data);
if(result)
return result;
}
}
if(blen) {
@ -469,6 +474,9 @@ CURLcode Curl_req_stop_send_recv(struct Curl_easy *data)
/* stop receiving and ALL sending as well, including PAUSE and HOLD.
* We might still be paused on receive client writes though, so
* keep those bits around. */
CURLcode result = CURLE_OK;
if(data->req.keepon & KEEP_SEND)
result = Curl_req_abort_sending(data);
data->req.keepon &= ~(KEEP_RECV|KEEP_SEND);
return Curl_req_abort_sending(data);
return result;
}

3
lib/sendf.c
View file

@ -230,7 +230,8 @@ static CURLcode cw_download_write(struct Curl_easy *data,
size_t nwrite, excess_len = 0;
bool is_connect = !!(type & CLIENTWRITE_CONNECT);
if(!is_connect && !ctx->started_response) {
if(!ctx->started_response &&
!(type & (CLIENTWRITE_INFO|CLIENTWRITE_CONNECT))) {
Curl_pgrsTime(data, TIMER_STARTTRANSFER);
Curl_rlimit_start(&data->progress.dl.rlimit, curlx_now());
ctx->started_response = TRUE;

13
lib/transfer.c
View file

@ -301,18 +301,7 @@ static CURLcode sendrecv_dl(struct Curl_easy *data,
/* We only get a 0-length receive at the end of the response */
is_eos = (blen == 0);
if(!blen && (conn->recv[FIRSTSOCKET] == Curl_cf_recv)) {
/* if we receive 0 or less here and the protocol handler did not
replace the connection's `recv` callback, either the data transfer
is done or the server closed the connection and
we bail out from this!
With a `recv` replacement, we assume the protocol handler knows
what it is doing and a 0-length receive is fine. For example,
SFTP downloads of an empty file would show this. See #19165. */
if(is_multiplex)
DEBUGF(infof(data, "nread == 0, stream closed, bailing"));
else
DEBUGF(infof(data, "nread <= 0, server closed connection, bailing"));
if(!blen) {
result = Curl_req_stop_send_recv(data);
if(result)
goto out;

1
lib/url.c
View file

@ -3834,6 +3834,7 @@ CURLcode Curl_connect(struct Curl_easy *data,
if(!result) {
DEBUGASSERT(conn);
Curl_pgrsTime(data, TIMER_POSTQUEUE);
if(reused) {
if(CONN_ATTACHED(conn) > 1)
/* multiplexed */

8
lib/vquic/curl_osslq.c
View file

@ -1803,6 +1803,14 @@ static CURLcode cf_osslq_connect(struct Curl_cfilter *cf,
if(err == 1) {
/* connected */
if(!ctx->got_first_byte) {
/* if not recorded yet, take the timestamp before we called
* SSL_do_handshake() as the time we received the first packet. */
ctx->got_first_byte = TRUE;
ctx->first_byte_at = now;
}
/* Record the handshake complete with a new time stamp. */
now = curlx_now();
ctx->handshake_at = now;
ctx->q.last_io = now;
CURL_TRC_CF(data, cf, "handshake complete after %" FMT_TIMEDIFF_T "ms",

6
tests/http/test_02_download.py
View file

@ -43,6 +43,7 @@ class TestDownload:
@pytest.fixture(autouse=True, scope='class')
def _class_scope(self, env, httpd):
indir = httpd.docs_dir
env.make_data_file(indir=indir, fname="data-0k", fsize=0)
env.make_data_file(indir=indir, fname="data-10k", fsize=10*1024)
env.make_data_file(indir=indir, fname="data-100k", fsize=100*1024)
env.make_data_file(indir=indir, fname="data-1m", fsize=1024*1024)
@ -52,9 +53,10 @@ class TestDownload:
# download 1 file
@pytest.mark.parametrize("proto", Env.http_protos())
def test_02_01_download_1(self, env: Env, httpd, nghttpx, proto):
@pytest.mark.parametrize("docname", ['data.json', 'data-0k', 'data-10k', 'data-100k'])
def test_02_01_download_1(self, env: Env, httpd, nghttpx, proto, docname):
curl = CurlClient(env=env)
url = f'https://{env.authority_for(env.domain1, proto)}/data.json'
url = f'https://{env.authority_for(env.domain1, proto)}/{docname}'
r = curl.http_download(urls=[url], alpn_proto=proto)
r.check_response(http_status=200)

56
tests/http/test_16_info.py
View file

@ -56,6 +56,7 @@ class TestInfo:
remote_ip='127.0.0.1')
for idx, s in enumerate(r.stats):
self.check_stat(idx, s, r, dl_size=30, ul_size=0)
r.check_stats_timeline(idx)
# download plain file with a 302 redirect
@pytest.mark.parametrize("proto", Env.http_protos())
@ -71,6 +72,7 @@ class TestInfo:
remote_ip='127.0.0.1')
for idx, s in enumerate(r.stats):
self.check_stat(idx, s, r, dl_size=30, ul_size=0)
r.check_stats_timeline(idx)
@pytest.mark.parametrize("proto", Env.http_protos())
def test_16_03_info_upload(self, env: Env, httpd, nghttpx, proto):
@ -89,6 +91,7 @@ class TestInfo:
remote_ip='127.0.0.1')
for idx, s in enumerate(r.stats):
self.check_stat(idx, s, r, dl_size=fsize, ul_size=fsize)
r.check_stats_timeline(idx)
# download plain file via http: ('time_appconnect' is 0)
@pytest.mark.parametrize("proto", ['http/1.1'])
@ -101,9 +104,9 @@ class TestInfo:
remote_port=env.http_port, remote_ip='127.0.0.1')
for idx, s in enumerate(r.stats):
self.check_stat(idx, s, r, dl_size=30, ul_size=0)
r.check_stats_timeline(idx)
def check_stat(self, idx, s, r, dl_size=None, ul_size=None):
self.check_stat_times(s, idx)
# we always send something
self.check_stat_positive(s, idx, 'size_request')
# we always receive response headers
@ -118,54 +121,3 @@ class TestInfo:
def check_stat_positive(self, s, idx, key):
assert key in s, f'stat #{idx} "{key}" missing: {s}'
assert s[key] > 0, f'stat #{idx} "{key}" not positive: {s}'
def check_stat_positive_or_0(self, s, idx, key):
assert key in s, f'stat #{idx} "{key}" missing: {s}'
assert s[key] >= 0, f'stat #{idx} "{key}" not positive: {s}'
def check_stat_zero(self, s, key):
assert key in s, f'stat "{key}" missing: {s}'
assert s[key] == 0, f'stat "{key}" not zero: {s}'
def check_stat_times(self, s, idx):
# check timings reported on a transfer for consistency
url = s['url_effective']
# connect time is sometimes reported as 0 by openssl-quic (sigh)
self.check_stat_positive_or_0(s, idx, 'time_connect')
# all stat keys which reporting timings
all_keys = {
'time_appconnect', 'time_redirect',
'time_pretransfer', 'time_starttransfer', 'time_total'
}
# stat keys where we expect a positive value
pos_keys = {'time_pretransfer', 'time_starttransfer', 'time_total', 'time_queue'}
if s['num_connects'] > 0:
if url.startswith('https:'):
pos_keys.add('time_appconnect')
if s['num_redirects'] > 0:
pos_keys.add('time_redirect')
zero_keys = all_keys - pos_keys
# assert all zeros are zeros and the others are positive
for key in zero_keys:
self.check_stat_zero(s, key)
for key in pos_keys:
self.check_stat_positive(s, idx, key)
# assert that all timers before "time_pretransfer" are less or equal
for key in ['time_appconnect', 'time_connect', 'time_namelookup']:
assert s[key] < s['time_pretransfer'], f'time "{key}" larger than' \
f'"time_pretransfer": {s}'
# assert transfer total is after pretransfer.
# (in MOST situations, pretransfer is before starttransfer, BUT
# in protocols like HTTP we might get a server response already before
# we transition to multi state DID.)
assert s['time_pretransfer'] <= s['time_total'], f'"time_pretransfer" '\
f'greater than "time_total", {s}'
# assert that transfer start is before total
assert s['time_starttransfer'] <= s['time_total'], f'"time_starttransfer" '\
f'greater than "time_total", {s}'
if s['num_redirects'] > 0:
assert s['time_queue'] < s['time_starttransfer'], f'"time_queue" '\
f'greater/equal than "time_starttransfer", {s}'
else:
assert s['time_queue'] <= s['time_starttransfer'], f'"time_queue" '\
f'greater than "time_starttransfer", {s}'

21
tests/http/test_30_vsftpd.py
View file

@ -63,10 +63,12 @@ class TestVsFTPD:
shutil.rmtree(vsftpd.docs_dir)
if not os.path.exists(vsftpd.docs_dir):
os.makedirs(vsftpd.docs_dir)
self._make_docs_file(docs_dir=vsftpd.docs_dir, fname='data-0k', fsize=0)
self._make_docs_file(docs_dir=vsftpd.docs_dir, fname='data-1k', fsize=1024)
self._make_docs_file(docs_dir=vsftpd.docs_dir, fname='data-10k', fsize=10*1024)
self._make_docs_file(docs_dir=vsftpd.docs_dir, fname='data-1m', fsize=1024*1024)
self._make_docs_file(docs_dir=vsftpd.docs_dir, fname='data-10m', fsize=10*1024*1024)
env.make_data_file(indir=env.gen_dir, fname="upload-0k", fsize=0)
env.make_data_file(indir=env.gen_dir, fname="upload-1k", fsize=1024)
env.make_data_file(indir=env.gen_dir, fname="upload-100k", fsize=100*1024)
env.make_data_file(indir=env.gen_dir, fname="upload-1m", fsize=1024*1024)
@ -77,11 +79,12 @@ class TestVsFTPD:
r = curl.ftp_get(urls=[url], with_stats=True)
r.check_stats(count=1, http_status=226)
lines = open(os.path.join(curl.run_dir, 'download_#1.data')).readlines()
assert len(lines) == 4, f'list: {lines}'
assert len(lines) == 5, f'list: {lines}'
r.check_stats_timelines()
# download 1 file, no SSL
@pytest.mark.parametrize("docname", [
'data-1k', 'data-1m', 'data-10m'
'data-0k', 'data-1k', 'data-1m', 'data-10m'
])
def test_30_02_download_1(self, env: Env, vsftpd: VsFTPD, docname):
curl = CurlClient(env=env)
@ -91,9 +94,10 @@ class TestVsFTPD:
r = curl.ftp_get(urls=[url], with_stats=True)
r.check_stats(count=count, http_status=226)
self.check_downloads(curl, srcfile, count)
r.check_stats_timelines()
@pytest.mark.parametrize("docname", [
'data-1k', 'data-1m', 'data-10m'
'data-0k', 'data-1k', 'data-1m', 'data-10m'
])
def test_30_03_download_10_serial(self, env: Env, vsftpd: VsFTPD, docname):
curl = CurlClient(env=env)
@ -104,9 +108,10 @@ class TestVsFTPD:
r.check_stats(count=count, http_status=226)
self.check_downloads(curl, srcfile, count)
assert r.total_connects == count + 1, 'should reuse the control conn'
r.check_stats_timelines()
@pytest.mark.parametrize("docname", [
'data-1k', 'data-1m', 'data-10m'
'data-0k', 'data-1k', 'data-1m', 'data-10m'
])
def test_30_04_download_10_parallel(self, env: Env, vsftpd: VsFTPD, docname):
curl = CurlClient(env=env)
@ -119,9 +124,10 @@ class TestVsFTPD:
r.check_stats(count=count, http_status=226)
self.check_downloads(curl, srcfile, count)
assert r.total_connects > count + 1, 'should have used several control conns'
r.check_stats_timelines()
@pytest.mark.parametrize("docname", [
'upload-1k', 'upload-100k', 'upload-1m'
'upload-0k', 'upload-1k', 'upload-100k', 'upload-1m'
])
def test_30_05_upload_1(self, env: Env, vsftpd: VsFTPD, docname):
curl = CurlClient(env=env)
@ -133,6 +139,7 @@ class TestVsFTPD:
r = curl.ftp_upload(urls=[url], fupload=f'{srcfile}', with_stats=True)
r.check_stats(count=count, http_status=226)
self.check_upload(env, vsftpd, docname=docname)
r.check_stats_timelines()
def _rmf(self, path):
if os.path.exists(path):
@ -188,6 +195,7 @@ class TestVsFTPD:
])
r.check_stats(count=count, http_status=226)
self.check_downloads(curl, srcfile, count)
r.check_stats_timelines()
def test_30_09_active_up_file(self, env: Env, vsftpd: VsFTPD):
docname = 'upload-1k'
@ -202,6 +210,7 @@ class TestVsFTPD:
])
r.check_stats(count=count, http_status=226)
self.check_upload(env, vsftpd, docname=docname)
r.check_stats_timelines()
def test_30_10_active_up_ascii(self, env: Env, vsftpd: VsFTPD):
docname = 'upload-1k'
@ -216,6 +225,7 @@ class TestVsFTPD:
])
r.check_stats(count=count, http_status=226)
self.check_upload(env, vsftpd, docname=docname, binary=False)
r.check_stats_timelines()
def test_30_11_download_non_existing(self, env: Env, vsftpd: VsFTPD):
curl = CurlClient(env=env)
@ -223,6 +233,7 @@ class TestVsFTPD:
r = curl.ftp_get(urls=[url], with_stats=True)
r.check_exit_code(78)
r.check_stats(count=1, exitcode=78)
r.check_stats_timelines()
def check_downloads(self, client, srcfile: str, count: int,
complete: bool = True):

5
tests/http/test_31_vsftpds.py
View file

@ -85,6 +85,7 @@ class TestVsFTPD:
r.check_stats(count=1, http_status=226)
lines = open(os.path.join(curl.run_dir, 'download_#1.data')).readlines()
assert len(lines) == 4, f'list: {lines}'
r.check_stats_timelines()
# download 1 file, no SSL
@pytest.mark.parametrize("docname", [
@ -98,6 +99,7 @@ class TestVsFTPD:
r = curl.ftp_ssl_get(urls=[url], with_stats=True)
r.check_stats(count=count, http_status=226)
self.check_downloads(curl, srcfile, count)
r.check_stats_timelines()
@pytest.mark.parametrize("docname", [
'data-1k', 'data-1m', 'data-10m'
@ -111,6 +113,7 @@ class TestVsFTPD:
r.check_stats(count=count, http_status=226)
self.check_downloads(curl, srcfile, count)
assert r.total_connects == count + 1, 'should reuse the control conn'
r.check_stats_timelines()
@pytest.mark.parametrize("docname", [
'data-1k', 'data-1m', 'data-10m'
@ -126,6 +129,7 @@ class TestVsFTPD:
r.check_stats(count=count, http_status=226)
self.check_downloads(curl, srcfile, count)
assert r.total_connects > count + 1, 'should have used several control conns'
r.check_stats_timelines()
@pytest.mark.parametrize("docname", [
'upload-1k', 'upload-100k', 'upload-1m'
@ -140,6 +144,7 @@ class TestVsFTPD:
r = curl.ftp_ssl_upload(urls=[url], fupload=f'{srcfile}', with_stats=True)
r.check_stats(count=count, http_status=226)
self.check_upload(env, vsftpds, docname=docname)
r.check_stats_timelines()
def _rmf(self, path):
if os.path.exists(path):

6
tests/http/test_32_ftps_vsftpd.py
View file

@ -85,6 +85,7 @@ class TestFtpsVsFTPD:
r.check_stats(count=1, http_status=226)
lines = open(os.path.join(curl.run_dir, 'download_#1.data')).readlines()
assert len(lines) == 4, f'list: {lines}'
r.check_stats_timelines()
# download 1 file, no SSL
@pytest.mark.parametrize("docname", [
@ -98,6 +99,7 @@ class TestFtpsVsFTPD:
r = curl.ftp_get(urls=[url], with_stats=True)
r.check_stats(count=count, http_status=226)
self.check_downloads(curl, srcfile, count)
r.check_stats_timelines()
@pytest.mark.parametrize("docname", [
'data-1k', 'data-1m', 'data-10m'
@ -111,6 +113,7 @@ class TestFtpsVsFTPD:
r.check_stats(count=count, http_status=226)
self.check_downloads(curl, srcfile, count)
assert r.total_connects == count + 1, 'should reuse the control conn'
r.check_stats_timelines()
# 2 serial transfers, first with 'ftps://' and second with 'ftp://'
# we want connection reuse in this case
@ -123,6 +126,7 @@ class TestFtpsVsFTPD:
r = curl.ftp_get(urls=[url1, url2], with_stats=True)
r.check_stats(count=count, http_status=226)
assert r.total_connects == count + 1, 'should reuse the control conn'
r.check_stats_timelines()
@pytest.mark.parametrize("docname", [
'data-1k', 'data-1m', 'data-10m'
@ -138,6 +142,7 @@ class TestFtpsVsFTPD:
r.check_stats(count=count, http_status=226)
self.check_downloads(curl, srcfile, count)
assert r.total_connects > count + 1, 'should have used several control conns'
r.check_stats_timelines()
@pytest.mark.parametrize("docname", [
'upload-1k', 'upload-100k', 'upload-1m'
@ -152,6 +157,7 @@ class TestFtpsVsFTPD:
r = curl.ftp_upload(urls=[url], fupload=f'{srcfile}', with_stats=True)
r.check_stats(count=count, http_status=226)
self.check_upload(env, vsftpds, docname=docname)
r.check_stats_timelines()
def _rmf(self, path):
if os.path.exists(path):

74
tests/http/testenv/curl.py
View file

@ -493,6 +493,80 @@ class ExecResult:
f'status #{idx} remote_ip: expected {remote_ip}, '\
f'got {x["remote_ip"]}\n{self.dump_stat(x)}'
def check_stat_positive(self, s, idx, key):
assert key in s, f'stat #{idx} "{key}" missing: {s}'
assert s[key] > 0, f'stat #{idx} "{key}" not positive: {s}'
def check_stat_positive_or_0(self, s, idx, key):
assert key in s, f'stat #{idx} "{key}" missing: {s}'
assert s[key] >= 0, f'stat #{idx} "{key}" not positive: {s}'
def check_stat_zero(self, s, key):
assert key in s, f'stat "{key}" missing: {s}'
assert s[key] == 0, f'stat "{key}" not zero: {s}'
def check_stats_timelines(self):
for i in range(len(self._stats)):
self.check_stats_timeline(i)
def check_stats_timeline(self, idx):
# check timings reported on a transfer for consistency
s = self._stats[idx]
url = s['url_effective']
# connect time is sometimes reported as 0 by openssl-quic (sigh)
self.check_stat_positive_or_0(s, idx, 'time_connect')
# all stat keys which reporting timings
all_keys = {
'time_queue', 'time_namelookup',
'time_connect', 'time_appconnect',
'time_pretransfer', 'time_posttransfer',
'time_starttransfer', 'time_total',
}
# stat keys where we expect a positive value
ref_tl = []
exact_match = True
# redirects mess up the queue time, only count without
if s['time_redirect'] == 0:
ref_tl += ['time_queue']
else:
exact_match = False
# connect events?
if url.startswith('ftp'):
# ftp is messy with connect events for its DATA connection
exact_match = False
elif s['num_connects'] > 0:
ref_tl += ['time_namelookup', 'time_connect']
if url.startswith('https:'):
ref_tl += ['time_appconnect']
# what kind of transfer was it?
if s['size_upload'] == 0 and s['size_download'] > 0:
# this is a download
dl_tl = ['time_pretransfer', 'time_starttransfer']
if s['size_request'] > 0:
dl_tl = ['time_posttransfer'] + dl_tl
ref_tl += dl_tl
elif s['size_upload'] > 0 and s['size_download'] == 0:
# this is an upload
ul_tl = ['time_pretransfer', 'time_posttransfer']
ref_tl += ul_tl
else:
# could be a 0-length upload or 0-length download, not sure
exact_match = False
# always there at the end
ref_tl += ['time_total']
# assert all events in reference timeline are > 0
for key in ref_tl:
self.check_stat_positive(s, idx, key)
if exact_match:
# assert all events not in reference timeline are 0
for key in [key for key in all_keys if key not in ref_tl]:
self.check_stat_zero(s, key)
# calculate the timeline that did happen
seen_tl = sorted(ref_tl, key=lambda ts: s[ts])
assert seen_tl == ref_tl, f'{[f"{ts}: {s[ts]}" for ts in seen_tl]}'
def dump_logs(self):
lines = ['>>--stdout ----------------------------------------------\n']
lines.extend(self._stdout)

5
tests/libtest/lib500.c
View file

@ -128,7 +128,10 @@ static CURLcode test_lib500(const char *URL)
(time_pretransfer / 1000000),
(long)(time_pretransfer % 1000000));
}
if(time_pretransfer > time_posttransfer) {
if(time_posttransfer > time_pretransfer) {
/* counter-intuitive: on a GET request, all bytes are sent *before*
* PRETRANSFER happens. Thus POSTTRANSFER has to be smaller.
* The reverse would be true for a POST/PUT. */
curl_mfprintf(moo, "pretransfer vs posttransfer: %"
CURL_FORMAT_CURL_OFF_T
".%06ld %" CURL_FORMAT_CURL_OFF_T ".%06ld\n",