romenskiy2012/curl
1
0
Fork 0
mirror of https://github.com/curl/curl.git synced 2026-08-26 11:13:36 +03:00
Code Issues Projects Releases Packages Wiki Activity

trace: make tracing available in non-debug builds

Browse source 
Add --trace-config to curl

Add curl_global_trace() to libcurl

Closes #11421
This commit is contained in:
Stefan Eissing 2023-08-03 17:32:25 +02:00 • committed by Daniel Stenberg
parent 0f49b5bacb
commit e12b39e133
No known key found for this signature in database
GPG key ID: 5CC908FDB71E12C2
46 changed files with 1166 additions and 790 deletions
Download patch file Download diff file Expand all files Collapse all files

4
lib/Makefile.inc
View file

@ -124,7 +124,6 @@ LIB_CFILES = \
curl_get_line.c \
curl_gethostname.c \
curl_gssapi.c \
curl_log.c \
curl_memrchr.c \
curl_multibyte.c \
curl_ntlm_core.c \
@ -135,6 +134,7 @@ LIB_CFILES = \
curl_sasl.c \
curl_sspi.c \
curl_threads.c \
curl_trc.c \
dict.c \
doh.c \
dynbuf.c \
@ -260,7 +260,6 @@ LIB_HFILES = \
curl_hmac.h \
curl_krb5.h \
curl_ldap.h \
curl_log.h \
curl_md4.h \
curl_md5.h \
curl_memory.h \
@ -278,6 +277,7 @@ LIB_HFILES = \
curl_sha256.h \
curl_sspi.h \
curl_threads.h \
curl_trc.h \
curlx.h \
dict.h \
doh.h \

34
lib/cf-h1-proxy.c
View file

@ -41,7 +41,7 @@
#include "cfilters.h"
#include "cf-h1-proxy.h"
#include "connect.h"
#include "curl_log.h"
#include "curl_trc.h"
#include "curlx.h"
#include "vtls/vtls.h"
#include "transfer.h"
@ -175,36 +175,36 @@ static void h1_tunnel_go_state(struct Curl_cfilter *cf,
/* entering this one */
switch(new_state) {
case H1_TUNNEL_INIT:
DEBUGF(LOG_CF(data, cf, "new tunnel state 'init'"));
CURL_TRC_CF(data, cf, "new tunnel state 'init'");
tunnel_reinit(ts, cf->conn, data);
break;
case H1_TUNNEL_CONNECT:
DEBUGF(LOG_CF(data, cf, "new tunnel state 'connect'"));
CURL_TRC_CF(data, cf, "new tunnel state 'connect'");
ts->tunnel_state = H1_TUNNEL_CONNECT;
ts->keepon = KEEPON_CONNECT;
Curl_dyn_reset(&ts->rcvbuf);
break;
case H1_TUNNEL_RECEIVE:
DEBUGF(LOG_CF(data, cf, "new tunnel state 'receive'"));
CURL_TRC_CF(data, cf, "new tunnel state 'receive'");
ts->tunnel_state = H1_TUNNEL_RECEIVE;
break;
case H1_TUNNEL_RESPONSE:
DEBUGF(LOG_CF(data, cf, "new tunnel state 'response'"));
CURL_TRC_CF(data, cf, "new tunnel state 'response'");
ts->tunnel_state = H1_TUNNEL_RESPONSE;
break;
case H1_TUNNEL_ESTABLISHED:
DEBUGF(LOG_CF(data, cf, "new tunnel state 'established'"));
CURL_TRC_CF(data, cf, "new tunnel state 'established'");
infof(data, "CONNECT phase completed");
data->state.authproxy.done = TRUE;
data->state.authproxy.multipass = FALSE;
/* FALLTHROUGH */
case H1_TUNNEL_FAILED:
if(new_state == H1_TUNNEL_FAILED)
DEBUGF(LOG_CF(data, cf, "new tunnel state 'failed'"));
CURL_TRC_CF(data, cf, "new tunnel state 'failed'");
ts->tunnel_state = new_state;
Curl_dyn_reset(&ts->rcvbuf);
Curl_dyn_reset(&ts->req);
@ -416,7 +416,7 @@ static CURLcode on_resp_header(struct Curl_cfilter *cf,
if(!auth)
return CURLE_OUT_OF_MEMORY;
DEBUGF(LOG_CF(data, cf, "CONNECT: fwd auth header '%s'", header));
CURL_TRC_CF(data, cf, "CONNECT: fwd auth header '%s'", header);
result = Curl_http_input_auth(data, proxy, auth);
free(auth);
@ -638,7 +638,7 @@ static CURLcode recv_CONNECT_resp(struct Curl_cfilter *cf,
/* without content-length or chunked encoding, we
can't keep the connection alive since the close is
the end signal so we bail out at once instead */
DEBUGF(LOG_CF(data, cf, "CONNECT: no content-length or chunked"));
CURL_TRC_CF(data, cf, "CONNECT: no content-length or chunked");
ts->keepon = KEEPON_DONE;
}
}
@ -977,7 +977,7 @@ static CURLcode H1_CONNECT(struct Curl_cfilter *cf,
switch(ts->tunnel_state) {
case H1_TUNNEL_INIT:
/* Prepare the CONNECT request and make a first attempt to send. */
DEBUGF(LOG_CF(data, cf, "CONNECT start"));
CURL_TRC_CF(data, cf, "CONNECT start");
result = start_CONNECT(cf, data, ts);
if(result)
goto out;
@ -986,7 +986,7 @@ static CURLcode H1_CONNECT(struct Curl_cfilter *cf,
case H1_TUNNEL_CONNECT:
/* see that the request is completely sent */
DEBUGF(LOG_CF(data, cf, "CONNECT send"));
CURL_TRC_CF(data, cf, "CONNECT send");
result = send_CONNECT(data, cf->conn, ts, &done);
if(result || !done)
goto out;
@ -995,7 +995,7 @@ static CURLcode H1_CONNECT(struct Curl_cfilter *cf,
case H1_TUNNEL_RECEIVE:
/* read what is there */
DEBUGF(LOG_CF(data, cf, "CONNECT receive"));
CURL_TRC_CF(data, cf, "CONNECT receive");
result = recv_CONNECT_resp(cf, data, ts, &done);
if(Curl_pgrsUpdate(data)) {
result = CURLE_ABORTED_BY_CALLBACK;
@ -1009,7 +1009,7 @@ static CURLcode H1_CONNECT(struct Curl_cfilter *cf,
/* FALLTHROUGH */
case H1_TUNNEL_RESPONSE:
DEBUGF(LOG_CF(data, cf, "CONNECT response"));
CURL_TRC_CF(data, cf, "CONNECT response");
if(data->req.newurl) {
/* not the "final" response, we need to do a follow up request.
* If the other side indicated a connection close, or if someone
@ -1021,7 +1021,7 @@ static CURLcode H1_CONNECT(struct Curl_cfilter *cf,
* reset our tunnel state. To avoid recursion, we return
* and expect to be called again.
*/
DEBUGF(LOG_CF(data, cf, "CONNECT need to close+open"));
CURL_TRC_CF(data, cf, "CONNECT need to close+open");
infof(data, "Connect me again please");
Curl_conn_cf_close(cf, data);
connkeep(conn, "HTTP proxy CONNECT");
@ -1075,7 +1075,7 @@ static CURLcode cf_h1_proxy_connect(struct Curl_cfilter *cf,
return CURLE_OK;
}
DEBUGF(LOG_CF(data, cf, "connect"));
CURL_TRC_CF(data, cf, "connect");
result = cf->next->cft->do_connect(cf->next, data, blocking, done);
if(result || !*done)
return result;
@ -1135,14 +1135,14 @@ static int cf_h1_proxy_get_select_socks(struct Curl_cfilter *cf,
static void cf_h1_proxy_destroy(struct Curl_cfilter *cf,
struct Curl_easy *data)
{
DEBUGF(LOG_CF(data, cf, "destroy"));
CURL_TRC_CF(data, cf, "destroy");
tunnel_free(cf, data);
}
static void cf_h1_proxy_close(struct Curl_cfilter *cf,
struct Curl_easy *data)
{
DEBUGF(LOG_CF(data, cf, "close"));
CURL_TRC_CF(data, cf, "close");
cf->connected = FALSE;
if(cf->ctx) {
h1_tunnel_go_state(cf, cf->ctx, H1_TUNNEL_INIT, data);

172
lib/cf-h2-proxy.c
View file

@ -30,7 +30,7 @@
#include "urldata.h"
#include "cfilters.h"
#include "connect.h"
#include "curl_log.h"
#include "curl_trc.h"
#include "bufq.h"
#include "dynbuf.h"
#include "dynhds.h"
@ -146,29 +146,29 @@ static void h2_tunnel_go_state(struct Curl_cfilter *cf,
/* entering this one */
switch(new_state) {
case H2_TUNNEL_INIT:
DEBUGF(LOG_CF(data, cf, "new tunnel state 'init'"));
CURL_TRC_CF(data, cf, "new tunnel state 'init'");
tunnel_stream_clear(ts);
break;
case H2_TUNNEL_CONNECT:
DEBUGF(LOG_CF(data, cf, "new tunnel state 'connect'"));
CURL_TRC_CF(data, cf, "new tunnel state 'connect'");
ts->state = H2_TUNNEL_CONNECT;
break;
case H2_TUNNEL_RESPONSE:
DEBUGF(LOG_CF(data, cf, "new tunnel state 'response'"));
CURL_TRC_CF(data, cf, "new tunnel state 'response'");
ts->state = H2_TUNNEL_RESPONSE;
break;
case H2_TUNNEL_ESTABLISHED:
DEBUGF(LOG_CF(data, cf, "new tunnel state 'established'"));
CURL_TRC_CF(data, cf, "new tunnel state 'established'");
infof(data, "CONNECT phase completed");
data->state.authproxy.done = TRUE;
data->state.authproxy.multipass = FALSE;
/* FALLTHROUGH */
case H2_TUNNEL_FAILED:
if(new_state == H2_TUNNEL_FAILED)
DEBUGF(LOG_CF(data, cf, "new tunnel state 'failed'"));
CURL_TRC_CF(data, cf, "new tunnel state 'failed'");
ts->state = new_state;
/* If a proxy-authorization header was used for the proxy, then we should
make sure that it isn't accidentally used for the document request
@ -232,8 +232,8 @@ static void drain_tunnel(struct Curl_cfilter *cf,
if(!tunnel->closed && !tunnel->reset && tunnel->upload_blocked_len)
bits |= CURL_CSELECT_OUT;
if(data->state.dselect_bits != bits) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] DRAIN dselect_bits=%x",
tunnel->stream_id, bits));
CURL_TRC_CF(data, cf, "[h2sid=%d] DRAIN dselect_bits=%x",
tunnel->stream_id, bits);
data->state.dselect_bits = bits;
Curl_expire(data, 0, EXPIRE_RUN_NOW);
}
@ -248,8 +248,8 @@ static ssize_t proxy_nw_in_reader(void *reader_ctx,
ssize_t nread;
nread = Curl_conn_cf_recv(cf->next, data, (char *)buf, buflen, err);
DEBUGF(LOG_CF(data, cf, "nw_in_reader(len=%zu) -> %zd, %d",
buflen, nread, *err));
CURL_TRC_CF(data, cf, "nw_in_reader(len=%zu) -> %zd, %d",
buflen, nread, *err);
return nread;
}
@ -262,8 +262,8 @@ static ssize_t proxy_h2_nw_out_writer(void *writer_ctx,
ssize_t nwritten;
nwritten = Curl_conn_cf_send(cf->next, data, (const char *)buf, buflen, err);
DEBUGF(LOG_CF(data, cf, "nw_out_writer(len=%zu) -> %zd, %d",
buflen, nwritten, *err));
CURL_TRC_CF(data, cf, "nw_out_writer(len=%zu) -> %zd, %d",
buflen, nwritten, *err);
return nwritten;
}
@ -384,7 +384,7 @@ static CURLcode cf_h2_proxy_ctx_init(struct Curl_cfilter *cf,
out:
if(cbs)
nghttp2_session_callbacks_del(cbs);
DEBUGF(LOG_CF(data, cf, "init proxy ctx -> %d", result));
CURL_TRC_CF(data, cf, "init proxy ctx -> %d", result);
return result;
}
@ -409,13 +409,13 @@ static CURLcode proxy_h2_nw_out_flush(struct Curl_cfilter *cf,
&result);
if(nwritten < 0) {
if(result == CURLE_AGAIN) {
DEBUGF(LOG_CF(data, cf, "flush nw send buffer(%zu) -> EAGAIN",
Curl_bufq_len(&ctx->outbufq)));
CURL_TRC_CF(data, cf, "flush nw send buffer(%zu) -> EAGAIN",
Curl_bufq_len(&ctx->outbufq));
ctx->nw_out_blocked = 1;
}
return result;
}
DEBUGF(LOG_CF(data, cf, "nw send buffer flushed"));
CURL_TRC_CF(data, cf, "nw send buffer flushed");
return Curl_bufq_is_empty(&ctx->outbufq)? CURLE_OK: CURLE_AGAIN;
}
@ -436,8 +436,7 @@ static int proxy_h2_process_pending_input(struct Curl_cfilter *cf,
while(Curl_bufq_peek(&ctx->inbufq, &buf, &blen)) {
rv = nghttp2_session_mem_recv(ctx->h2, (const uint8_t *)buf, blen);
DEBUGF(LOG_CF(data, cf,
"fed %zu bytes from nw to nghttp2 -> %zd", blen, rv));
CURL_TRC_CF(data, cf, "fed %zu bytes from nw to nghttp2 -> %zd", blen, rv);
if(rv < 0) {
failf(data,
"process_pending_input: nghttp2_session_mem_recv() returned "
@ -447,12 +446,12 @@ static int proxy_h2_process_pending_input(struct Curl_cfilter *cf,
}
Curl_bufq_skip(&ctx->inbufq, (size_t)rv);
if(Curl_bufq_is_empty(&ctx->inbufq)) {
DEBUGF(LOG_CF(data, cf, "all data in connection buffer processed"));
CURL_TRC_CF(data, cf, "all data in connection buffer processed");
break;
}
else {
DEBUGF(LOG_CF(data, cf, "process_pending_input: %zu bytes left "
"in connection buffer", Curl_bufq_len(&ctx->inbufq)));
CURL_TRC_CF(data, cf, "process_pending_input: %zu bytes left "
"in connection buffer", Curl_bufq_len(&ctx->inbufq));
}
}
@ -468,8 +467,8 @@ static CURLcode proxy_h2_progress_ingress(struct Curl_cfilter *cf,
/* Process network input buffer fist */
if(!Curl_bufq_is_empty(&ctx->inbufq)) {
DEBUGF(LOG_CF(data, cf, "Process %zu bytes in connection buffer",
Curl_bufq_len(&ctx->inbufq)));
CURL_TRC_CF(data, cf, "Process %zu bytes in connection buffer",
Curl_bufq_len(&ctx->inbufq));
if(proxy_h2_process_pending_input(cf, data, &result) < 0)
return result;
}
@ -482,8 +481,8 @@ static CURLcode proxy_h2_progress_ingress(struct Curl_cfilter *cf,
!Curl_bufq_is_full(&ctx->tunnel.recvbuf)) {
nread = Curl_bufq_slurp(&ctx->inbufq, proxy_nw_in_reader, cf, &result);
DEBUGF(LOG_CF(data, cf, "read %zu bytes nw data -> %zd, %d",
Curl_bufq_len(&ctx->inbufq), nread, result));
CURL_TRC_CF(data, cf, "read %zu bytes nw data -> %zd, %d",
Curl_bufq_len(&ctx->inbufq), nread, result);
if(nread < 0) {
if(result != CURLE_AGAIN) {
failf(data, "Failed receiving HTTP2 data");
@ -518,8 +517,8 @@ static CURLcode proxy_h2_progress_egress(struct Curl_cfilter *cf,
rv = nghttp2_session_send(ctx->h2);
if(nghttp2_is_fatal(rv)) {
DEBUGF(LOG_CF(data, cf, "nghttp2_session_send error (%s)%d",
nghttp2_strerror(rv), rv));
CURL_TRC_CF(data, cf, "nghttp2_session_send error (%s)%d",
nghttp2_strerror(rv), rv);
return CURLE_SEND_ERROR;
}
return proxy_h2_nw_out_flush(cf, data);
@ -579,27 +578,26 @@ static int proxy_h2_on_frame_recv(nghttp2_session *session,
ctx->goaway = TRUE;
break;
case NGHTTP2_WINDOW_UPDATE:
DEBUGF(LOG_CF(data, cf, "recv frame WINDOW_UPDATE"));
CURL_TRC_CF(data, cf, "recv frame WINDOW_UPDATE");
break;
default:
DEBUGF(LOG_CF(data, cf, "recv frame %x on 0", frame->hd.type));
CURL_TRC_CF(data, cf, "recv frame %x on 0", frame->hd.type);
}
return 0;
}
if(stream_id != ctx->tunnel.stream_id) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] rcvd FRAME not for tunnel",
stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%u] rcvd FRAME not for tunnel", stream_id);
return NGHTTP2_ERR_CALLBACK_FAILURE;
}
switch(frame->hd.type) {
case NGHTTP2_DATA:
/* If body started on this stream, then receiving DATA is illegal. */
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv frame DATA", stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%u] recv frame DATA", stream_id);
break;
case NGHTTP2_HEADERS:
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv frame HEADERS", stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%u] recv frame HEADERS", stream_id);
/* nghttp2 guarantees that :status is received, and we store it to
stream->status_code. Fuzzing has proven this can still be reached
@ -607,8 +605,8 @@ static int proxy_h2_on_frame_recv(nghttp2_session *session,
if(!ctx->tunnel.resp)
return NGHTTP2_ERR_CALLBACK_FAILURE;
/* Only final status code signals the end of header */
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] got http status: %d",
stream_id, ctx->tunnel.resp->status));
CURL_TRC_CF(data, cf, "[h2sid=%u] got http status: %d",
stream_id, ctx->tunnel.resp->status);
if(!ctx->tunnel.has_final_response) {
if(ctx->tunnel.resp->status / 100 != 1) {
ctx->tunnel.has_final_response = TRUE;
@ -616,25 +614,25 @@ static int proxy_h2_on_frame_recv(nghttp2_session *session,
}
break;
case NGHTTP2_PUSH_PROMISE:
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv PUSH_PROMISE", stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%u] recv PUSH_PROMISE", stream_id);
return NGHTTP2_ERR_CALLBACK_FAILURE;
case NGHTTP2_RST_STREAM:
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv RST", stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%u] recv RST", stream_id);
ctx->tunnel.reset = TRUE;
break;
case NGHTTP2_WINDOW_UPDATE:
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv WINDOW_UPDATE", stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%u] recv WINDOW_UPDATE", stream_id);
if((data->req.keepon & KEEP_SEND_HOLD) &&
(data->req.keepon & KEEP_SEND)) {
data->req.keepon &= ~KEEP_SEND_HOLD;
Curl_expire(data, 0, EXPIRE_RUN_NOW);
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] unpausing after win update",
stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%u] unpausing after win update",
stream_id);
}
break;
default:
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv frame %x",
stream_id, frame->hd.type));
CURL_TRC_CF(data, cf, "[h2sid=%u] recv frame %x",
stream_id, frame->hd.type);
break;
}
return 0;
@ -658,10 +656,9 @@ static int proxy_h2_on_header(nghttp2_session *session,
(void)session;
DEBUGASSERT(stream_id); /* should never be a zero stream ID here */
if(stream_id != ctx->tunnel.stream_id) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] header for non-tunnel stream: "
"%.*s: %.*s", stream_id,
(int)namelen, name,
(int)valuelen, value));
CURL_TRC_CF(data, cf, "[h2sid=%u] header for non-tunnel stream: "
"%.*s: %.*s", stream_id,
(int)namelen, name, (int)valuelen, value);
return NGHTTP2_ERR_CALLBACK_FAILURE;
}
@ -689,8 +686,8 @@ static int proxy_h2_on_header(nghttp2_session *session,
return NGHTTP2_ERR_CALLBACK_FAILURE;
resp->prev = ctx->tunnel.resp;
ctx->tunnel.resp = resp;
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] status: HTTP/2 %03d",
stream_id, ctx->tunnel.resp->status));
CURL_TRC_CF(data, cf, "[h2sid=%u] status: HTTP/2 %03d",
stream_id, ctx->tunnel.resp->status);
return 0;
}
@ -703,10 +700,8 @@ static int proxy_h2_on_header(nghttp2_session *session,
if(result)
return NGHTTP2_ERR_CALLBACK_FAILURE;
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] header: %.*s: %.*s",
stream_id,
(int)namelen, name,
(int)valuelen, value));
CURL_TRC_CF(data, cf, "[h2sid=%u] header: %.*s: %.*s",
stream_id, (int)namelen, name, (int)valuelen, value);
return 0; /* 0 is successful */
}
@ -746,8 +741,8 @@ static ssize_t tunnel_send_callback(nghttp2_session *session,
if(ts->closed && Curl_bufq_is_empty(&ts->sendbuf))
*data_flags = NGHTTP2_DATA_FLAG_EOF;
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] tunnel_send_callback -> %zd",
ts->stream_id, nread));
CURL_TRC_CF(data, cf, "[h2sid=%u] tunnel_send_callback -> %zd",
ts->stream_id, nread);
return nread;
}
@ -791,8 +786,8 @@ static int proxy_h2_on_stream_close(nghttp2_session *session,
if(stream_id != ctx->tunnel.stream_id)
return 0;
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] proxy_h2_on_stream_close, %s (err %d)",
stream_id, nghttp2_http2_strerror(error_code), error_code));
CURL_TRC_CF(data, cf, "[h2sid=%u] proxy_h2_on_stream_close, %s (err %d)",
stream_id, nghttp2_http2_strerror(error_code), error_code);
ctx->tunnel.closed = TRUE;
ctx->tunnel.error = error_code;
@ -910,8 +905,8 @@ static CURLcode submit_CONNECT(struct Curl_cfilter *cf,
result = proxy_h2_submit(&ts->stream_id, cf, data, ctx->h2, req,
NULL, ts, tunnel_send_callback, cf);
if(result) {
DEBUGF(LOG_CF(data, cf, "send: nghttp2_submit_request error (%s)%u",
nghttp2_strerror(ts->stream_id), ts->stream_id));
CURL_TRC_CF(data, cf, "send: nghttp2_submit_request error (%s)%u",
nghttp2_strerror(ts->stream_id), ts->stream_id);
}
out:
@ -945,8 +940,8 @@ static CURLcode inspect_response(struct Curl_cfilter *cf,
}
if(auth_reply) {
DEBUGF(LOG_CF(data, cf, "CONNECT: fwd auth header '%s'",
auth_reply->value));
CURL_TRC_CF(data, cf, "CONNECT: fwd auth header '%s'",
auth_reply->value);
result = Curl_http_input_auth(data, ts->resp->status == 407,
auth_reply->value);
if(result)
@ -976,7 +971,7 @@ static CURLcode H2_CONNECT(struct Curl_cfilter *cf,
switch(ts->state) {
case H2_TUNNEL_INIT:
/* Prepare the CONNECT request and make a first attempt to send. */
DEBUGF(LOG_CF(data, cf, "CONNECT start for %s", ts->authority));
CURL_TRC_CF(data, cf, "CONNECT start for %s", ts->authority);
result = submit_CONNECT(cf, data, ts);
if(result)
goto out;
@ -1143,8 +1138,8 @@ static ssize_t h2_handle_tunnel_close(struct Curl_cfilter *cf,
ssize_t rv = 0;
if(ctx->tunnel.error == NGHTTP2_REFUSED_STREAM) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] REFUSED_STREAM, try again on a new "
"connection", ctx->tunnel.stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%u] REFUSED_STREAM, try again on a new "
"connection", ctx->tunnel.stream_id);
connclose(cf->conn, "REFUSED_STREAM"); /* don't use this anymore */
*err = CURLE_RECV_ERROR; /* trigger Curl_retry_request() later */
return -1;
@ -1164,7 +1159,7 @@ static ssize_t h2_handle_tunnel_close(struct Curl_cfilter *cf,
*err = CURLE_OK;
rv = 0;
DEBUGF(LOG_CF(data, cf, "handle_tunnel_close -> %zd, %d", rv, *err));
CURL_TRC_CF(data, cf, "handle_tunnel_close -> %zd, %d", rv, *err);
return rv;
}
@ -1200,8 +1195,8 @@ static ssize_t tunnel_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
}
out:
DEBUGF(LOG_CF(data, cf, "tunnel_recv(len=%zu) -> %zd, %d",
len, nread, *err));
CURL_TRC_CF(data, cf, "tunnel_recv(len=%zu) -> %zd, %d",
len, nread, *err);
return nread;
}
@ -1229,8 +1224,8 @@ static ssize_t cf_h2_proxy_recv(struct Curl_cfilter *cf,
nread = tunnel_recv(cf, data, buf, len, err);
if(nread > 0) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] increase window by %zd",
ctx->tunnel.stream_id, nread));
CURL_TRC_CF(data, cf, "[h2sid=%u] increase window by %zd",
ctx->tunnel.stream_id, nread);
nghttp2_session_consume(ctx->h2, ctx->tunnel.stream_id, (size_t)nread);
}
@ -1247,8 +1242,8 @@ out:
* draining to avoid stalling when no socket events happen. */
drain_tunnel(cf, data, &ctx->tunnel);
}
DEBUGF(LOG_CF(data, cf, "[h2sid=%u] cf_recv(len=%zu) -> %zd %d",
ctx->tunnel.stream_id, len, nread, *err));
CURL_TRC_CF(data, cf, "[h2sid=%u] cf_recv(len=%zu) -> %zd %d",
ctx->tunnel.stream_id, len, nread, *err);
CF_DATA_RESTORE(cf, save);
return nread;
}
@ -1346,19 +1341,19 @@ static ssize_t cf_h2_proxy_send(struct Curl_cfilter *cf,
* proxy connection AND to UNHOLD all of them again when the
* window increases.
* We *could* iterate over all data on this conn maybe? */
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] remote flow "
"window is exhausted", ctx->tunnel.stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%d] remote flow "
"window is exhausted", ctx->tunnel.stream_id);
}
/* Whatever the cause, we need to return CURL_EAGAIN for this call.
* We have unwritten state that needs us being invoked again and EAGAIN
* is the only way to ensure that. */
ctx->tunnel.upload_blocked_len = nwritten;
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) BLOCK: win %u/%zu "
"blocked_len=%zu",
ctx->tunnel.stream_id, len,
nghttp2_session_get_remote_window_size(ctx->h2), rwin,
nwritten));
CURL_TRC_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) BLOCK: win %u/%zu "
"blocked_len=%zu",
ctx->tunnel.stream_id, len,
nghttp2_session_get_remote_window_size(ctx->h2), rwin,
nwritten);
*err = CURLE_AGAIN;
nwritten = -1;
goto out;
@ -1371,22 +1366,21 @@ static ssize_t cf_h2_proxy_send(struct Curl_cfilter *cf,
nwritten = -1;
}
else {
DEBUGF(LOG_CF(data, cf, "send: nothing to do in this session"));
CURL_TRC_CF(data, cf, "send: nothing to do in this session");
*err = CURLE_HTTP2;
nwritten = -1;
}
}
out:
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) -> %zd, %d, "
"h2 windows %d-%d (stream-conn), "
"buffers %zu-%zu (stream-conn)",
ctx->tunnel.stream_id, len, nwritten, *err,
nghttp2_session_get_stream_remote_window_size(
CURL_TRC_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) -> %zd, %d, "
"h2 windows %d-%d (stream-conn), buffers %zu-%zu (stream-conn)",
ctx->tunnel.stream_id, len, nwritten, *err,
nghttp2_session_get_stream_remote_window_size(
ctx->h2, ctx->tunnel.stream_id),
nghttp2_session_get_remote_window_size(ctx->h2),
Curl_bufq_len(&ctx->tunnel.sendbuf),
Curl_bufq_len(&ctx->outbufq)));
nghttp2_session_get_remote_window_size(ctx->h2),
Curl_bufq_len(&ctx->tunnel.sendbuf),
Curl_bufq_len(&ctx->outbufq));
CF_DATA_RESTORE(cf, save);
return nwritten;
}
@ -1438,8 +1432,8 @@ static bool cf_h2_proxy_is_alive(struct Curl_cfilter *cf,
CF_DATA_SAVE(save, cf, data);
result = (ctx && ctx->h2 && proxy_h2_connisalive(cf, data, input_pending));
DEBUGF(LOG_CF(data, cf, "conn alive -> %d, input_pending=%d",
result, *input_pending));
CURL_TRC_CF(data, cf, "conn alive -> %d, input_pending=%d",
result, *input_pending);
CF_DATA_RESTORE(cf, save);
return result;
}
@ -1447,7 +1441,7 @@ static bool cf_h2_proxy_is_alive(struct Curl_cfilter *cf,
struct Curl_cftype Curl_cft_h2_proxy = {
"H2-PROXY",
CF_TYPE_IP_CONNECT,
CURL_LOG_DEFAULT,
CURL_LOG_LVL_NONE,
cf_h2_proxy_destroy,
cf_h2_proxy_connect,
cf_h2_proxy_close,

6
lib/cf-haproxy.c
View file

@ -30,7 +30,7 @@
#include "urldata.h"
#include "cfilters.h"
#include "cf-haproxy.h"
#include "curl_log.h"
#include "curl_trc.h"
#include "multiif.h"
/* The last 3 #include files should be in this order */
@ -157,14 +157,14 @@ static void cf_haproxy_destroy(struct Curl_cfilter *cf,
struct Curl_easy *data)
{
(void)data;
DEBUGF(LOG_CF(data, cf, "destroy"));
CURL_TRC_CF(data, cf, "destroy");
cf_haproxy_ctx_free(cf->ctx);
}
static void cf_haproxy_close(struct Curl_cfilter *cf,
struct Curl_easy *data)
{
DEBUGF(LOG_CF(data, cf, "close"));
CURL_TRC_CF(data, cf, "close");
cf->connected = FALSE;
cf_haproxy_ctx_reset(cf->ctx);
if(cf->next)

38
lib/cf-https-connect.c
View file

@ -28,7 +28,7 @@
#include "urldata.h"
#include <curl/curl.h>
#include "curl_log.h"
#include "curl_trc.h"
#include "cfilters.h"
#include "connect.h"
#include "multiif.h"
@ -165,9 +165,9 @@ static CURLcode baller_connected(struct Curl_cfilter *cf,
if(winner != &ctx->h21_baller)
cf_hc_baller_reset(&ctx->h21_baller, data);
DEBUGF(LOG_CF(data, cf, "connect+handshake %s: %dms, 1st data: %dms",
winner->name, (int)Curl_timediff(Curl_now(), winner->started),
cf_hc_baller_reply_ms(winner, data)));
CURL_TRC_CF(data, cf, "connect+handshake %s: %dms, 1st data: %dms",
winner->name, (int)Curl_timediff(Curl_now(), winner->started),
cf_hc_baller_reply_ms(winner, data));
cf->next = winner->cf;
winner->cf = NULL;
@ -218,16 +218,16 @@ static bool time_to_start_h21(struct Curl_cfilter *cf,
elapsed_ms = Curl_timediff(now, ctx->started);
if(elapsed_ms >= ctx->hard_eyeballs_timeout_ms) {
DEBUGF(LOG_CF(data, cf, "hard timeout of %dms reached, starting h21",
ctx->hard_eyeballs_timeout_ms));
CURL_TRC_CF(data, cf, "hard timeout of %dms reached, starting h21",
ctx->hard_eyeballs_timeout_ms);
return TRUE;
}
if(elapsed_ms >= ctx->soft_eyeballs_timeout_ms) {
if(cf_hc_baller_reply_ms(&ctx->h3_baller, data) < 0) {
DEBUGF(LOG_CF(data, cf, "soft timeout of %dms reached, h3 has not "
"seen any data, starting h21",
ctx->soft_eyeballs_timeout_ms));
CURL_TRC_CF(data, cf, "soft timeout of %dms reached, h3 has not "
"seen any data, starting h21",
ctx->soft_eyeballs_timeout_ms);
return TRUE;
}
/* set the effective hard timeout again */
@ -258,7 +258,7 @@ static CURLcode cf_hc_connect(struct Curl_cfilter *cf,
DEBUGASSERT(!ctx->h3_baller.cf);
DEBUGASSERT(!ctx->h21_baller.cf);
DEBUGASSERT(!cf->next);
DEBUGF(LOG_CF(data, cf, "connect, init"));
CURL_TRC_CF(data, cf, "connect, init");
ctx->started = now;
if(ctx->h3_baller.enabled) {
cf_hc_baller_init(&ctx->h3_baller, cf, data, "h3", TRNSPRT_QUIC);
@ -286,7 +286,7 @@ static CURLcode cf_hc_connect(struct Curl_cfilter *cf,
}
if(cf_hc_baller_is_active(&ctx->h21_baller)) {
DEBUGF(LOG_CF(data, cf, "connect, check h21"));
CURL_TRC_CF(data, cf, "connect, check h21");
result = cf_hc_baller_connect(&ctx->h21_baller, cf, data, done);
if(!result && *done) {
result = baller_connected(cf, data, &ctx->h21_baller);
@ -297,7 +297,7 @@ static CURLcode cf_hc_connect(struct Curl_cfilter *cf,
if((!ctx->h3_baller.enabled || ctx->h3_baller.result) &&
(!ctx->h21_baller.enabled || ctx->h21_baller.result)) {
/* both failed or disabled. we give up */
DEBUGF(LOG_CF(data, cf, "connect, all failed"));
CURL_TRC_CF(data, cf, "connect, all failed");
result = ctx->result = ctx->h3_baller.enabled?
ctx->h3_baller.result : ctx->h21_baller.result;
ctx->state = CF_HC_FAILURE;
@ -321,7 +321,7 @@ static CURLcode cf_hc_connect(struct Curl_cfilter *cf,
}
out:
DEBUGF(LOG_CF(data, cf, "connect -> %d, done=%d", result, *done));
CURL_TRC_CF(data, cf, "connect -> %d, done=%d", result, *done);
return result;
}
@ -345,7 +345,7 @@ static int cf_hc_get_select_socks(struct Curl_cfilter *cf,
if(!cf_hc_baller_is_active(b))
continue;
brc = Curl_conn_cf_get_select_socks(b->cf, data, bsocks);
DEBUGF(LOG_CF(data, cf, "get_selected_socks(%s) -> %x", b->name, brc));
CURL_TRC_CF(data, cf, "get_selected_socks(%s) -> %x", b->name, brc);
if(!brc)
continue;
for(j = 0; j < MAX_SOCKSPEREASYHANDLE && s < MAX_SOCKSPEREASYHANDLE; ++j) {
@ -359,7 +359,7 @@ static int cf_hc_get_select_socks(struct Curl_cfilter *cf,
}
}
}
DEBUGF(LOG_CF(data, cf, "get_selected_socks -> %x", rc));
CURL_TRC_CF(data, cf, "get_selected_socks -> %x", rc);
return rc;
}
@ -371,7 +371,7 @@ static bool cf_hc_data_pending(struct Curl_cfilter *cf,
if(cf->connected)
return cf->next->cft->has_data_pending(cf->next, data);
DEBUGF(LOG_CF((struct Curl_easy *)data, cf, "data_pending"));
CURL_TRC_CF((struct Curl_easy *)data, cf, "data_pending");
return cf_hc_baller_data_pending(&ctx->h3_baller, data)
|| cf_hc_baller_data_pending(&ctx->h21_baller, data);
}
@ -427,7 +427,7 @@ static CURLcode cf_hc_query(struct Curl_cfilter *cf,
static void cf_hc_close(struct Curl_cfilter *cf, struct Curl_easy *data)
{
DEBUGF(LOG_CF(data, cf, "close"));
CURL_TRC_CF(data, cf, "close");
cf_hc_reset(cf, data);
cf->connected = FALSE;
@ -442,7 +442,7 @@ static void cf_hc_destroy(struct Curl_cfilter *cf, struct Curl_easy *data)
struct cf_hc_ctx *ctx = cf->ctx;
(void)data;
DEBUGF(LOG_CF(data, cf, "destroy"));
CURL_TRC_CF(data, cf, "destroy");
cf_hc_reset(cf, data);
Curl_safefree(ctx);
}
@ -450,7 +450,7 @@ static void cf_hc_destroy(struct Curl_cfilter *cf, struct Curl_easy *data)
struct Curl_cftype Curl_cft_http_connect = {
"HTTPS-CONNECT",
0,
CURL_LOG_DEFAULT,
CURL_LOG_LVL_NONE,
cf_hc_destroy,
cf_hc_connect,
cf_hc_close,

88
lib/cf-socket.c
View file

@ -632,7 +632,7 @@ static CURLcode bindlocal(struct Curl_easy *data, struct connectdata *conn,
port++; /* try next port */
if(port == 0)
break;
infof(data, "Bind to local port %hu failed, trying next", port - 1);
infof(data, "Bind to local port %d failed, trying next", port - 1);
/* We re-use/clobber the port variable here below */
if(sock->sa_family == AF_INET)
si4->sin_port = ntohs(port);
@ -836,8 +836,8 @@ static ssize_t nw_in_read(void *reader_ctx,
nread = -1;
}
}
DEBUGF(LOG_CF(rctx->data, rctx->cf, "nw_in_read(len=%zu) -> %d, err=%d",
len, (int)nread, *err));
CURL_TRC_CF(rctx->data, rctx->cf, "nw_in_read(len=%zu) -> %d, err=%d",
len, (int)nread, *err);
return nread;
}
@ -852,14 +852,14 @@ static void cf_socket_close(struct Curl_cfilter *cf, struct Curl_easy *data)
* closed it) and we just forget about it.
*/
if(ctx->sock == cf->conn->sock[cf->sockindex]) {
DEBUGF(LOG_CF(data, cf, "cf_socket_close(%" CURL_FORMAT_SOCKET_T
", active)", ctx->sock));
CURL_TRC_CF(data, cf, "cf_socket_close(%" CURL_FORMAT_SOCKET_T
", active)", ctx->sock);
socket_close(data, cf->conn, !ctx->accepted, ctx->sock);
cf->conn->sock[cf->sockindex] = CURL_SOCKET_BAD;
}
else {
DEBUGF(LOG_CF(data, cf, "cf_socket_close(%" CURL_FORMAT_SOCKET_T
") no longer at conn->sock[], discarding", ctx->sock));
CURL_TRC_CF(data, cf, "cf_socket_close(%" CURL_FORMAT_SOCKET_T
") no longer at conn->sock[], discarding", ctx->sock);
/* TODO: we do not want this to happen. Need to check which
* code is messing with conn->sock[cf->sockindex] */
}
@ -869,8 +869,8 @@ static void cf_socket_close(struct Curl_cfilter *cf, struct Curl_easy *data)
}
else {
/* this is our local socket, we did never publish it */
DEBUGF(LOG_CF(data, cf, "cf_socket_close(%" CURL_FORMAT_SOCKET_T
", not active)", ctx->sock));
CURL_TRC_CF(data, cf, "cf_socket_close(%" CURL_FORMAT_SOCKET_T
", not active)", ctx->sock);
socket_close(data, cf->conn, !ctx->accepted, ctx->sock);
ctx->sock = CURL_SOCKET_BAD;
}
@ -889,7 +889,7 @@ static void cf_socket_destroy(struct Curl_cfilter *cf, struct Curl_easy *data)
struct cf_socket_ctx *ctx = cf->ctx;
cf_socket_close(cf, data);
DEBUGF(LOG_CF(data, cf, "destroy"));
CURL_TRC_CF(data, cf, "destroy");
Curl_bufq_free(&ctx->recvbuf);
free(ctx);
cf->ctx = NULL;
@ -1047,8 +1047,8 @@ out:
ctx->connected_at = Curl_now();
cf->connected = TRUE;
}
DEBUGF(LOG_CF(data, cf, "cf_socket_open() -> %d, fd=%" CURL_FORMAT_SOCKET_T,
result, ctx->sock));
CURL_TRC_CF(data, cf, "cf_socket_open() -> %d, fd=%" CURL_FORMAT_SOCKET_T,
result, ctx->sock);
return result;
}
@ -1155,7 +1155,7 @@ static CURLcode cf_tcp_connect(struct Curl_cfilter *cf,
rc = SOCKET_WRITABLE(ctx->sock, 0);
if(rc == 0) { /* no connection yet */
DEBUGF(LOG_CF(data, cf, "not connected yet"));
CURL_TRC_CF(data, cf, "not connected yet");
return CURLE_OK;
}
else if(rc == CURL_CSELECT_OUT || cf->conn->bits.tcp_fastopen) {
@ -1165,7 +1165,7 @@ static CURLcode cf_tcp_connect(struct Curl_cfilter *cf,
set_local_ip(cf, data);
*done = TRUE;
cf->connected = TRUE;
DEBUGF(LOG_CF(data, cf, "connected"));
CURL_TRC_CF(data, cf, "connected");
return CURLE_OK;
}
}
@ -1288,8 +1288,8 @@ static ssize_t cf_socket_send(struct Curl_cfilter *cf, struct Curl_easy *data,
}
}
DEBUGF(LOG_CF(data, cf, "send(len=%zu) -> %d, err=%d",
len, (int)nwritten, *err));
CURL_TRC_CF(data, cf, "send(len=%zu) -> %d, err=%d",
len, (int)nwritten, *err);
cf->conn->sock[cf->sockindex] = fdsave;
return nwritten;
}
@ -1307,7 +1307,7 @@ static ssize_t cf_socket_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
cf->conn->sock[cf->sockindex] = ctx->sock;
if(ctx->buffer_recv && !Curl_bufq_is_empty(&ctx->recvbuf)) {
DEBUGF(LOG_CF(data, cf, "recv from buffer"));
CURL_TRC_CF(data, cf, "recv from buffer");
nread = Curl_bufq_read(&ctx->recvbuf, (unsigned char *)buf, len, err);
}
else {
@ -1324,7 +1324,7 @@ static ssize_t cf_socket_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
if(nwritten < 0 && !Curl_bufq_is_empty(&ctx->recvbuf)) {
/* we have a partial read with an error. need to deliver
* what we got, return the error later. */
DEBUGF(LOG_CF(data, cf, "partial read: empty buffer first"));
CURL_TRC_CF(data, cf, "partial read: empty buffer first");
nread = Curl_bufq_read(&ctx->recvbuf, (unsigned char *)buf, len, err);
}
else if(nwritten < 0) {
@ -1337,7 +1337,7 @@ static ssize_t cf_socket_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
nread = 0;
}
else {
DEBUGF(LOG_CF(data, cf, "buffered %zd additional bytes", nwritten));
CURL_TRC_CF(data, cf, "buffered %zd additional bytes", nwritten);
nread = Curl_bufq_read(&ctx->recvbuf, (unsigned char *)buf, len, err);
}
}
@ -1347,8 +1347,8 @@ static ssize_t cf_socket_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
}
out:
DEBUGF(LOG_CF(data, cf, "recv(len=%zu) -> %d, err=%d", len, (int)nread,
*err));
CURL_TRC_CF(data, cf, "recv(len=%zu) -> %d, err=%d", len, (int)nread,
*err);
if(nread > 0 && !ctx->got_first_byte) {
ctx->first_byte_at = Curl_now();
ctx->got_first_byte = TRUE;
@ -1455,19 +1455,19 @@ static bool cf_socket_conn_is_alive(struct Curl_cfilter *cf,
r = Curl_poll(pfd, 1, 0);
if(r < 0) {
DEBUGF(LOG_CF(data, cf, "is_alive: poll error, assume dead"));
CURL_TRC_CF(data, cf, "is_alive: poll error, assume dead");
return FALSE;
}
else if(r == 0) {
DEBUGF(LOG_CF(data, cf, "is_alive: poll timeout, assume alive"));
CURL_TRC_CF(data, cf, "is_alive: poll timeout, assume alive");
return TRUE;
}
else if(pfd[0].revents & (POLLERR|POLLHUP|POLLPRI|POLLNVAL)) {
DEBUGF(LOG_CF(data, cf, "is_alive: err/hup/etc events, assume dead"));
CURL_TRC_CF(data, cf, "is_alive: err/hup/etc events, assume dead");
return FALSE;
}
DEBUGF(LOG_CF(data, cf, "is_alive: valid events, looks alive"));
CURL_TRC_CF(data, cf, "is_alive: valid events, looks alive");
*input_pending = TRUE;
return TRUE;
}
@ -1520,7 +1520,7 @@ static CURLcode cf_socket_query(struct Curl_cfilter *cf,
struct Curl_cftype Curl_cft_tcp = {
"TCP",
CF_TYPE_IP_CONNECT,
CURL_LOG_DEFAULT,
CURL_LOG_LVL_NONE,
cf_socket_destroy,
cf_tcp_connect,
cf_socket_close,
@ -1581,10 +1581,10 @@ static CURLcode cf_udp_setup_quic(struct Curl_cfilter *cf,
return socket_connect_result(data, ctx->r_ip, SOCKERRNO);
}
set_local_ip(cf, data);
DEBUGF(LOG_CF(data, cf, "%s socket %" CURL_FORMAT_SOCKET_T
" connected: [%s:%d] -> [%s:%d]",
(ctx->transport == TRNSPRT_QUIC)? "QUIC" : "UDP",
ctx->sock, ctx->l_ip, ctx->l_port, ctx->r_ip, ctx->r_port));
CURL_TRC_CF(data, cf, "%s socket %" CURL_FORMAT_SOCKET_T
" connected: [%s:%d] -> [%s:%d]",
(ctx->transport == TRNSPRT_QUIC)? "QUIC" : "UDP",
ctx->sock, ctx->l_ip, ctx->l_port, ctx->r_ip, ctx->r_port);
(void)curlx_nonblock(ctx->sock, TRUE);
switch(ctx->addr.family) {
@ -1624,7 +1624,7 @@ static CURLcode cf_udp_connect(struct Curl_cfilter *cf,
if(ctx->sock == CURL_SOCKET_BAD) {
result = cf_socket_open(cf, data);
if(result) {
DEBUGF(LOG_CF(data, cf, "cf_udp_connect(), open failed -> %d", result));
CURL_TRC_CF(data, cf, "cf_udp_connect(), open failed -> %d", result);
goto out;
}
@ -1632,13 +1632,13 @@ static CURLcode cf_udp_connect(struct Curl_cfilter *cf,
result = cf_udp_setup_quic(cf, data);
if(result)
goto out;
DEBUGF(LOG_CF(data, cf, "cf_udp_connect(), opened socket=%"
CURL_FORMAT_SOCKET_T " (%s:%d)",
ctx->sock, ctx->l_ip, ctx->l_port));
CURL_TRC_CF(data, cf, "cf_udp_connect(), opened socket=%"
CURL_FORMAT_SOCKET_T " (%s:%d)",
ctx->sock, ctx->l_ip, ctx->l_port);
}
else {
DEBUGF(LOG_CF(data, cf, "cf_udp_connect(), opened socket=%"
CURL_FORMAT_SOCKET_T " (unconnected)", ctx->sock));
CURL_TRC_CF(data, cf, "cf_udp_connect(), opened socket=%"
CURL_FORMAT_SOCKET_T " (unconnected)", ctx->sock);
}
*done = TRUE;
cf->connected = TRUE;
@ -1650,7 +1650,7 @@ out:
struct Curl_cftype Curl_cft_udp = {
"UDP",
CF_TYPE_IP_CONNECT,
CURL_LOG_DEFAULT,
CURL_LOG_LVL_NONE,
cf_socket_destroy,
cf_udp_connect,
cf_socket_close,
@ -1701,7 +1701,7 @@ out:
struct Curl_cftype Curl_cft_unix = {
"UNIX",
CF_TYPE_IP_CONNECT,
CURL_LOG_DEFAULT,
CURL_LOG_LVL_NONE,
cf_socket_destroy,
cf_tcp_connect,
cf_socket_close,
@ -1765,7 +1765,7 @@ static CURLcode cf_tcp_accept_connect(struct Curl_cfilter *cf,
struct Curl_cftype Curl_cft_tcp_accept = {
"TCP-ACCEPT",
CF_TYPE_IP_CONNECT,
CURL_LOG_DEFAULT,
CURL_LOG_LVL_NONE,
cf_socket_destroy,
cf_tcp_accept_connect,
cf_socket_close,
@ -1810,8 +1810,8 @@ CURLcode Curl_conn_tcp_listen_set(struct Curl_easy *data,
ctx->active = TRUE;
ctx->connected_at = Curl_now();
cf->connected = TRUE;
DEBUGF(LOG_CF(data, cf, "Curl_conn_tcp_listen_set(%"
CURL_FORMAT_SOCKET_T ")", ctx->sock));
CURL_TRC_CF(data, cf, "Curl_conn_tcp_listen_set(%"
CURL_FORMAT_SOCKET_T ")", ctx->sock);
out:
if(result) {
@ -1875,9 +1875,9 @@ CURLcode Curl_conn_tcp_accepted_set(struct Curl_easy *data,
ctx->accepted = TRUE;
ctx->connected_at = Curl_now();
cf->connected = TRUE;
DEBUGF(LOG_CF(data, cf, "accepted_set(sock=%" CURL_FORMAT_SOCKET_T
", remote=%s port=%d)",
ctx->sock, ctx->r_ip, ctx->r_port));
CURL_TRC_CF(data, cf, "accepted_set(sock=%" CURL_FORMAT_SOCKET_T
", remote=%s port=%d)",
ctx->sock, ctx->r_ip, ctx->r_port);
return CURLE_OK;
}

2
lib/cfilters.c
View file

@ -238,7 +238,7 @@ void Curl_conn_cf_add(struct Curl_easy *data,
cf->conn = conn;
cf->sockindex = index;
conn->cfilter[index] = cf;
DEBUGF(LOG_CF(data, cf, "added"));
CURL_TRC_CF(data, cf, "added");
}
void Curl_conn_cf_insert_after(struct Curl_cfilter *cf_at,

56
lib/connect.c
View file

@ -475,7 +475,7 @@ static void baller_initiate(struct Curl_cfilter *cf,
out:
if(result) {
DEBUGF(LOG_CF(data, cf, "%s failed", baller->name));
CURL_TRC_CF(data, cf, "%s failed", baller->name);
baller_close(baller, data);
}
if(cf_prev)
@ -601,8 +601,8 @@ evaluate:
continue;
}
baller->result = baller_connect(cf, data, baller, &now, connected);
DEBUGF(LOG_CF(data, cf, "%s connect -> %d, connected=%d",
baller->name, baller->result, *connected));
CURL_TRC_CF(data, cf, "%s connect -> %d, connected=%d",
baller->name, baller->result, *connected);
if(!baller->result) {
if(*connected) {
@ -623,11 +623,11 @@ evaluate:
}
baller_start_next(cf, data, baller, Curl_timeleft(data, &now, TRUE));
if(baller->is_done) {
DEBUGF(LOG_CF(data, cf, "%s done", baller->name));
CURL_TRC_CF(data, cf, "%s done", baller->name);
}
else {
/* next attempt was started */
DEBUGF(LOG_CF(data, cf, "%s trying next", baller->name));
CURL_TRC_CF(data, cf, "%s trying next", baller->name);
++ongoing;
}
}
@ -661,12 +661,12 @@ evaluate:
Curl_timediff(now, ctx->started) >= baller->delay_ms) {
baller_start(cf, data, baller, Curl_timeleft(data, &now, TRUE));
if(baller->is_done) {
DEBUGF(LOG_CF(data, cf, "%s done", baller->name));
CURL_TRC_CF(data, cf, "%s done", baller->name);
}
else {
DEBUGF(LOG_CF(data, cf, "%s starting (timeout=%"
CURL_FORMAT_TIMEDIFF_T "ms)",
baller->name, baller->timeoutms));
CURL_TRC_CF(data, cf, "%s starting (timeout=%"
CURL_FORMAT_TIMEDIFF_T "ms)",
baller->name, baller->timeoutms);
++ongoing;
++added;
}
@ -683,14 +683,14 @@ evaluate:
}
/* all ballers have failed to connect. */
DEBUGF(LOG_CF(data, cf, "all eyeballers failed"));
CURL_TRC_CF(data, cf, "all eyeballers failed");
result = CURLE_COULDNT_CONNECT;
for(i = 0; i < sizeof(ctx->baller)/sizeof(ctx->baller[0]); i++) {
struct eyeballer *baller = ctx->baller[i];
DEBUGF(LOG_CF(data, cf, "%s assess started=%d, result=%d",
baller?baller->name:NULL,
baller?baller->has_started:0,
baller?baller->result:0));
CURL_TRC_CF(data, cf, "%s assess started=%d, result=%d",
baller?baller->name:NULL,
baller?baller->has_started:0,
baller?baller->result:0);
if(baller && baller->has_started && baller->result) {
result = baller->result;
break;
@ -803,9 +803,9 @@ static CURLcode start_connect(struct Curl_cfilter *cf,
timeout_ms, EXPIRE_DNS_PER_NAME);
if(result)
return result;
DEBUGF(LOG_CF(data, cf, "created %s (timeout %"
CURL_FORMAT_TIMEDIFF_T "ms)",
ctx->baller[0]->name, ctx->baller[0]->timeoutms));
CURL_TRC_CF(data, cf, "created %s (timeout %"
CURL_FORMAT_TIMEDIFF_T "ms)",
ctx->baller[0]->name, ctx->baller[0]->timeoutms);
if(addr1) {
/* second one gets a delayed start */
result = eyeballer_new(&ctx->baller[1], ctx->cf_create, addr1, ai_family1,
@ -815,9 +815,9 @@ static CURLcode start_connect(struct Curl_cfilter *cf,
timeout_ms, EXPIRE_DNS_PER_NAME2);
if(result)
return result;
DEBUGF(LOG_CF(data, cf, "created %s (timeout %"
CURL_FORMAT_TIMEDIFF_T "ms)",
ctx->baller[1]->name, ctx->baller[1]->timeoutms));
CURL_TRC_CF(data, cf, "created %s (timeout %"
CURL_FORMAT_TIMEDIFF_T "ms)",
ctx->baller[1]->name, ctx->baller[1]->timeoutms);
}
Curl_expire(data, data->set.happy_eyeballs_timeout,
@ -931,7 +931,7 @@ static void cf_he_close(struct Curl_cfilter *cf,
{
struct cf_he_ctx *ctx = cf->ctx;
DEBUGF(LOG_CF(data, cf, "close"));
CURL_TRC_CF(data, cf, "close");
cf_he_ctx_clear(cf, data);
cf->connected = FALSE;
ctx->state = SCFST_INIT;
@ -1007,7 +1007,7 @@ static CURLcode cf_he_query(struct Curl_cfilter *cf,
}
}
*pres1 = reply_ms;
DEBUGF(LOG_CF(data, cf, "query connect reply: %dms", *pres1));
CURL_TRC_CF(data, cf, "query connect reply: %dms", *pres1);
return CURLE_OK;
}
case CF_QUERY_TIMER_CONNECT: {
@ -1034,7 +1034,7 @@ static void cf_he_destroy(struct Curl_cfilter *cf, struct Curl_easy *data)
{
struct cf_he_ctx *ctx = cf->ctx;
DEBUGF(LOG_CF(data, cf, "destroy"));
CURL_TRC_CF(data, cf, "destroy");
if(ctx) {
cf_he_ctx_clear(cf, data);
}
@ -1045,7 +1045,7 @@ static void cf_he_destroy(struct Curl_cfilter *cf, struct Curl_easy *data)
struct Curl_cftype Curl_cft_happy_eyeballs = {
"HAPPY-EYEBALLS",
0,
CURL_LOG_DEFAULT,
CURL_LOG_LVL_NONE,
cf_he_destroy,
cf_he_connect,
cf_he_close,
@ -1148,7 +1148,7 @@ static CURLcode cf_he_insert_after(struct Curl_cfilter *cf_at,
DEBUGASSERT(cf_at);
cf_create = get_cf_create(transport);
if(!cf_create) {
DEBUGF(LOG_CF(data, cf_at, "unsupported transport type %d", transport));
CURL_TRC_CF(data, cf_at, "unsupported transport type %d", transport);
return CURLE_UNSUPPORTED_PROTOCOL;
}
result = cf_happy_eyeballs_create(&cf, data, cf_at->conn,
@ -1286,7 +1286,7 @@ static void cf_setup_close(struct Curl_cfilter *cf,
{
struct cf_setup_ctx *ctx = cf->ctx;
DEBUGF(LOG_CF(data, cf, "close"));
CURL_TRC_CF(data, cf, "close");
cf->connected = FALSE;
ctx->state = CF_SETUP_INIT;
@ -1301,7 +1301,7 @@ static void cf_setup_destroy(struct Curl_cfilter *cf, struct Curl_easy *data)
struct cf_setup_ctx *ctx = cf->ctx;
(void)data;
DEBUGF(LOG_CF(data, cf, "destroy"));
CURL_TRC_CF(data, cf, "destroy");
Curl_safefree(ctx);
}
@ -1309,7 +1309,7 @@ static void cf_setup_destroy(struct Curl_cfilter *cf, struct Curl_easy *data)
struct Curl_cftype Curl_cft_setup = {
"SETUP",
0,
CURL_LOG_DEFAULT,
CURL_LOG_LVL_NONE,
cf_setup_destroy,
cf_setup_connect,
cf_setup_close,

121
lib/curl_log.h
View file

@ -1,121 +0,0 @@
#ifndef HEADER_CURL_LOG_H
#define HEADER_CURL_LOG_H
/***************************************************************************
* _ _ ____ _
* Project ___| | | | _ \| |
* / __| | | | |_) | |
* | (__| |_| | _ <| |___
* \___|\___/|_| \_\_____|
*
* Copyright (C) Daniel Stenberg, <daniel@haxx.se>, et al.
*
* This software is licensed as described in the file COPYING, which
* you should have received as part of this distribution. The terms
* are also available at https://curl.se/docs/copyright.html.
*
* You may opt to use, copy, modify, merge, publish, distribute and/or sell
* copies of the Software, and permit persons to whom the Software is
* furnished to do so, under the terms of the COPYING file.
*
* This software is distributed on an "AS IS" basis, WITHOUT WARRANTY OF ANY
* KIND, either express or implied.
*
* SPDX-License-Identifier: curl
*
***************************************************************************/
struct Curl_easy;
struct Curl_cfilter;
/**
* Init logging, return != 0 on failure.
*/
CURLcode Curl_log_init(void);
void Curl_infof(struct Curl_easy *, const char *fmt, ...);
void Curl_failf(struct Curl_easy *, const char *fmt, ...);
#if defined(CURL_DISABLE_VERBOSE_STRINGS)
#if defined(HAVE_VARIADIC_MACROS_C99)
#define infof(...) Curl_nop_stmt
#elif defined(HAVE_VARIADIC_MACROS_GCC)
#define infof(x...) Curl_nop_stmt
#else
#error "missing VARIADIC macro define, fix and rebuild!"
#endif
#else /* CURL_DISABLE_VERBOSE_STRINGS */
#define infof Curl_infof
#endif /* CURL_DISABLE_VERBOSE_STRINGS */
#define failf Curl_failf
#define CURL_LOG_DEFAULT 0
#define CURL_LOG_DEBUG 1
#define CURL_LOG_TRACE 2
/* the function used to output verbose information */
void Curl_debug(struct Curl_easy *data, curl_infotype type,
char *ptr, size_t size);
#ifdef DEBUGBUILD
/* explainer: we have some mix configuration and werror settings
* that define HAVE_VARIADIC_MACROS_C99 even though C89 is enforced
* on gnuc and some other compiler. Need to treat carefully.
*/
#if defined(HAVE_VARIADIC_MACROS_C99) && \
defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L)
#define LOG_CF(data, cf, ...) \
do { if(Curl_log_cf_is_debug(cf, data)) \
Curl_log_cf_debug(data, cf, __VA_ARGS__); } while(0)
#else
#define LOG_CF Curl_log_cf_debug
#endif
void Curl_log_cf_debug(struct Curl_easy *data, struct Curl_cfilter *cf,
#if defined(__GNUC__) && !defined(printf) && \
defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L) && \
!defined(__MINGW32__)
const char *fmt, ...)
__attribute__((format(printf, 3, 4)));
#else
const char *fmt, ...);
#endif
#define Curl_log_cf_is_debug(cf, data) \
((data) && (data)->set.verbose && \
(cf) && (cf)->cft->log_level >= CURL_LOG_DEBUG)
#else /* !DEBUGBUILD */
#if defined(HAVE_VARIADIC_MACROS_C99) && \
defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L)
#define LOG_CF(...) Curl_nop_stmt
#define Curl_log_cf_debug(...) Curl_nop_stmt
#elif defined(HAVE_VARIADIC_MACROS_GCC) && \
defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L)
#define LOG_CF(x...) Curl_nop_stmt
#define Curl_log_cf_debug(x...) Curl_nop_stmt
#else
#define LOG_CF Curl_log_cf_debug
/* without c99, we seem unable to completely define away this function. */
void Curl_log_cf_debug(struct Curl_easy *data, struct Curl_cfilter *cf,
const char *fmt, ...);
#endif
#define Curl_log_cf_is_debug(x,y) ((void)(x), (void)(y), FALSE)
#endif /* !DEBUGBUILD */
#define LOG_CF_IS_DEBUG(cf, data) Curl_log_cf_is_debug(cf, data)
#endif /* HEADER_CURL_LOG_H */

81
lib/curl_log.c → lib/curl_trc.c
View file

@ -26,7 +26,7 @@
#include <curl/curl.h>
#include "curl_log.h"
#include "curl_trc.h"
#include "urldata.h"
#include "easyif.h"
#include "cfilters.h"
@ -124,13 +124,13 @@ void Curl_infof(struct Curl_easy *data, const char *fmt, ...)
}
}
#ifdef DEBUGBUILD
#if !defined(CURL_DISABLE_VERBOSE_STRINGS)
void Curl_log_cf_debug(struct Curl_easy *data, struct Curl_cfilter *cf,
void Curl_trc_cf_infof(struct Curl_easy *data, struct Curl_cfilter *cf,
const char *fmt, ...)
{
DEBUGASSERT(cf);
if(data && Curl_log_cf_is_debug(cf, data)) {
if(data && Curl_trc_cf_is_verbose(cf, data)) {
va_list ap;
int len;
char buffer[MAXINFO + 2];
@ -179,44 +179,67 @@ static struct Curl_cftype *cf_types[] = {
NULL,
};
#ifndef ARRAYSIZE
#define ARRAYSIZE(A) (sizeof(A)/sizeof((A)[0]))
#endif
CURLcode Curl_log_init(void)
CURLcode Curl_trc_opt(const char *config)
{
const char *setting = getenv("CURL_DEBUG");
if(setting) {
char *token, *tok_buf, *tmp;
size_t i;
char *token, *tok_buf, *tmp;
size_t i;
int lvl;
tmp = strdup(setting);
if(!tmp)
return CURLE_OUT_OF_MEMORY;
tmp = strdup(config);
if(!tmp)
return CURLE_OUT_OF_MEMORY;
token = strtok_r(tmp, ", ", &tok_buf);
while(token) {
for(i = 0; cf_types[i]; ++i) {
if(strcasecompare(token, cf_types[i]->name)) {
cf_types[i]->log_level = CURL_LOG_DEBUG;
break;
}
}
token = strtok_r(NULL, ", ", &tok_buf);
token = strtok_r(tmp, ", ", &tok_buf);
while(token) {
switch(*token) {
case '-':
lvl = CURL_LOG_LVL_NONE;
++token;
break;
case '+':
lvl = CURL_LOG_LVL_INFO;
++token;
break;
default:
lvl = CURL_LOG_LVL_INFO;
break;
}
free(tmp);
for(i = 0; cf_types[i]; ++i) {
if(strcasecompare(token, "all")) {
cf_types[i]->log_level = lvl;
}
else if(strcasecompare(token, cf_types[i]->name)) {
cf_types[i]->log_level = lvl;
break;
}
}
token = strtok_r(NULL, ", ", &tok_buf);
}
free(tmp);
return CURLE_OK;
}
#else /* DEBUGBUILD */
CURLcode Curl_log_init(void)
CURLcode Curl_trc_init(void)
{
#ifdef DEBUGBUILD
/* WIP: we use the auto-init from an env var only in DEBUG builds for
* convenience. */
const char *config = getenv("CURL_DEBUG");
if(config) {
return Curl_trc_opt(config);
}
#endif
return CURLE_OK;
}
#else /* !CURL_DISABLE_VERBOSE_STRINGS) */
CURLcode Curl_trc_init(void)
{
return CURLE_OK;
}
#if !defined(__STDC_VERSION__) || (__STDC_VERSION__ < 199901L)
void Curl_log_cf_debug(struct Curl_easy *data, struct Curl_cfilter *cf,
void Curl_trc_cf_infof(struct Curl_easy *data, struct Curl_cfilter *cf,
const char *fmt, ...)
{
(void)data;

150
lib/curl_trc.h Normal file
View file

@ -0,0 +1,150 @@
#ifndef HEADER_CURL_TRC_H
#define HEADER_CURL_TRC_H
/***************************************************************************
* _ _ ____ _
* Project ___| | | | _ \| |
* / __| | | | |_) | |
* | (__| |_| | _ <| |___
* \___|\___/|_| \_\_____|
*
* Copyright (C) Daniel Stenberg, <daniel@haxx.se>, et al.
*
* This software is licensed as described in the file COPYING, which
* you should have received as part of this distribution. The terms
* are also available at https://curl.se/docs/copyright.html.
*
* You may opt to use, copy, modify, merge, publish, distribute and/or sell
* copies of the Software, and permit persons to whom the Software is
* furnished to do so, under the terms of the COPYING file.
*
* This software is distributed on an "AS IS" basis, WITHOUT WARRANTY OF ANY
* KIND, either express or implied.
*
* SPDX-License-Identifier: curl
*
***************************************************************************/
struct Curl_easy;
struct Curl_cfilter;
/**
* Init logging, return != 0 on failure.
*/
CURLcode Curl_trc_init(void);
/**
* Configure tracing. May be called several times during global
* initialization. Later calls may not take effect.
*
* Configuration format supported:
* - comma-separated list of component names to enable logging on.
* E.g. 'http/2,ssl'. Unkown names are ignored. Names are compared
* case-insensitive.
* - component 'all' applies to all known log components
* - prefixing a component with '+' or '-' will en-/disable logging for
* that component
* Example: 'all,-ssl' would enable logging for all components but the
* SSL filters.
*
* @param config configuration string
*/
CURLcode Curl_trc_opt(const char *config);
/* the function used to output verbose information */
void Curl_debug(struct Curl_easy *data, curl_infotype type,
char *ptr, size_t size);
/**
* Output an informational message when transfer's verbose logging is enabled.
*/
void Curl_infof(struct Curl_easy *data,
#if defined(__GNUC__) && !defined(printf) && \
defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L) && \
!defined(__MINGW32__)
const char *fmt, ...)
__attribute__((format(printf, 2, 3)));
#else
const char *fmt, ...);
#endif
/**
* Output a failure message on registered callbacks for transfer.
*/
void Curl_failf(struct Curl_easy *data,
#if defined(__GNUC__) && !defined(printf) && \
defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L) && \
!defined(__MINGW32__)
const char *fmt, ...)
__attribute__((format(printf, 2, 3)));
#else
const char *fmt, ...);
#endif
#define failf Curl_failf
/**
* Output an informational message when both transfer's verbose logging
* and connection filters verbose logging are enabled.
*/
void Curl_trc_cf_infof(struct Curl_easy *data, struct Curl_cfilter *cf,
#if defined(__GNUC__) && !defined(printf) && \
defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L) && \
!defined(__MINGW32__)
const char *fmt, ...)
__attribute__((format(printf, 3, 4)));
#else
const char *fmt, ...);
#endif
#define CURL_LOG_LVL_NONE 0
#define CURL_LOG_LVL_INFO 1
#if !defined(CURL_DISABLE_VERBOSE_STRINGS)
/* informational messages enabled */
#define Curl_trc_is_verbose(data) ((data) && (data)->set.verbose)
#define Curl_trc_cf_is_verbose(cf, data) \
((data) && (data)->set.verbose && \
(cf) && (cf)->cft->log_level >= CURL_LOG_LVL_INFO)
/* explainer: we have some mix configuration and werror settings
* that define HAVE_VARIADIC_MACROS_C99 even though C89 is enforced
* on gnuc and some other compiler. Need to treat carefully.
*/
#if defined(HAVE_VARIADIC_MACROS_C99) && \
defined(__STDC_VERSION__) && (__STDC_VERSION__ >= 199901L)
#define infof(data, ...) \
do { if(Curl_trc_is_verbose(data)) \
Curl_infof(data, __VA_ARGS__); } while(0)
#define CURL_TRC_CF(data, cf, ...) \
do { if(Curl_trc_cf_is_verbose(cf, data)) \
Curl_trc_cf_infof(data, cf, __VA_ARGS__); } while(0)
#else /* no variadic macro args */
#define infof Curl_infof
#define CURL_TRC_CF Curl_trc_cf_infof
#endif /* variadic macro args */
#else /* !CURL_DISABLE_VERBOSE_STRINGS */
/* All informational messages are not compiled in for size savings */
#define Curl_trc_is_verbose(d) ((void)(d), FALSE)
#define Curl_trc_cf_is_verbose(x,y) ((void)(x), (void)(y), FALSE)
#if defined(HAVE_VARIADIC_MACROS_C99)
#define infof(...) Curl_nop_stmt
#define CURL_TRC_CF(...) Curl_nop_stmt
#define Curl_trc_cf_infof(...) Curl_nop_stmt
#elif defined(HAVE_VARIADIC_MACROS_GCC)
#define infof(x...) Curl_nop_stmt
#define CURL_TRC_CF(x...) Curl_nop_stmt
#define Curl_trc_cf_infof(x...) Curl_nop_stmt
#else
#error "missing VARIADIC macro define, fix and rebuild!"
#endif
#endif /* CURL_DISABLE_VERBOSE_STRINGS */
#endif /* HEADER_CURL_TRC_H */

19
lib/easy.c
View file

@ -158,8 +158,8 @@ static CURLcode global_init(long flags, bool memoryfuncs)
#endif
}
if(Curl_log_init()) {
DEBUGF(fprintf(stderr, "Error: Curl_log_init failed\n"));
if(Curl_trc_init()) {
DEBUGF(fprintf(stderr, "Error: Curl_trc_init failed\n"));
goto fail;
}
@ -315,6 +315,21 @@ void curl_global_cleanup(void)
global_init_unlock();
}
/**
* curl_global_trace() globally initializes curl logging.
*/
CURLcode curl_global_trace(const char *config)
{
CURLcode result;
global_init_lock();
result = Curl_trc_opt(config);
global_init_unlock();
return result;
}
/*
* curl_global_sslset() globally initializes the SSL backend to use.
*/

257
lib/http2.c
View file

@ -217,8 +217,8 @@ static void drain_stream(struct Curl_cfilter *cf,
(stream->upload_left || stream->upload_blocked_len))
bits |= CURL_CSELECT_OUT;
if(data->state.dselect_bits != bits) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] DRAIN dselect_bits=%x",
stream->id, bits));
CURL_TRC_CF(data, cf, "[h2sid=%d] DRAIN dselect_bits=%x",
stream->id, bits);
data->state.dselect_bits = bits;
Curl_expire(data, 0, EXPIRE_RUN_NOW);
}
@ -281,8 +281,8 @@ static void http2_data_done(struct Curl_cfilter *cf,
if(ctx->h2) {
if(!stream->closed && stream->id > 0) {
/* RST_STREAM */
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] premature DATA_DONE, RST stream",
stream->id));
CURL_TRC_CF(data, cf, "[h2sid=%d] premature DATA_DONE, RST stream",
stream->id);
if(!nghttp2_submit_rst_stream(ctx->h2, NGHTTP2_FLAG_NONE,
stream->id, NGHTTP2_STREAM_CLOSED))
(void)nghttp2_session_send(ctx->h2);
@ -535,8 +535,8 @@ static int h2_process_pending_input(struct Curl_cfilter *cf,
break;
}
else {
DEBUGF(LOG_CF(data, cf, "process_pending_input: %zu bytes left "
"in connection buffer", Curl_bufq_len(&ctx->inbufq)));
CURL_TRC_CF(data, cf, "process_pending_input: %zu bytes left "
"in connection buffer", Curl_bufq_len(&ctx->inbufq));
}
}
@ -578,8 +578,8 @@ static bool http2_connisalive(struct Curl_cfilter *cf, struct Curl_easy *data,
*input_pending = FALSE;
nread = Curl_bufq_slurp(&ctx->inbufq, nw_in_reader, cf, &result);
if(nread != -1) {
DEBUGF(LOG_CF(data, cf, "%zd bytes stray data read before trying "
"h2 connection", nread));
CURL_TRC_CF(data, cf, "%zd bytes stray data read before trying "
"h2 connection", nread);
if(h2_process_pending_input(cf, data, &result) < 0)
/* immediate error, considered dead */
alive = FALSE;
@ -641,13 +641,13 @@ static CURLcode nw_out_flush(struct Curl_cfilter *cf,
nwritten = Curl_bufq_pass(&ctx->outbufq, nw_out_writer, cf, &result);
if(nwritten < 0) {
if(result == CURLE_AGAIN) {
DEBUGF(LOG_CF(data, cf, "flush nw send buffer(%zu) -> EAGAIN",
Curl_bufq_len(&ctx->outbufq)));
CURL_TRC_CF(data, cf, "flush nw send buffer(%zu) -> EAGAIN",
Curl_bufq_len(&ctx->outbufq));
ctx->nw_out_blocked = 1;
}
return result;
}
DEBUGF(LOG_CF(data, cf, "nw send buffer flushed"));
CURL_TRC_CF(data, cf, "nw send buffer flushed");
return Curl_bufq_is_empty(&ctx->outbufq)? CURLE_OK: CURLE_AGAIN;
}
@ -839,8 +839,8 @@ static int push_promise(struct Curl_cfilter *cf,
struct cf_h2_ctx *ctx = cf->ctx;
int rv; /* one of the CURL_PUSH_* defines */
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] PUSH_PROMISE received",
frame->promised_stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%d] PUSH_PROMISE received",
frame->promised_stream_id);
if(data->multi->push_cb) {
struct stream_ctx *stream;
struct stream_ctx *newstream;
@ -859,7 +859,7 @@ static int push_promise(struct Curl_cfilter *cf,
heads.data = data;
heads.frame = frame;
/* ask the application */
DEBUGF(LOG_CF(data, cf, "Got PUSH_PROMISE, ask application"));
CURL_TRC_CF(data, cf, "Got PUSH_PROMISE, ask application");
stream = H2_STREAM_CTX(data);
if(!stream) {
@ -931,7 +931,7 @@ static int push_promise(struct Curl_cfilter *cf,
}
}
else {
DEBUGF(LOG_CF(data, cf, "Got PUSH_PROMISE, ignore it"));
CURL_TRC_CF(data, cf, "Got PUSH_PROMISE, ignore it");
rv = CURL_PUSH_DENY;
}
fail:
@ -968,20 +968,20 @@ static CURLcode on_stream_frame(struct Curl_cfilter *cf,
int rv;
if(!stream) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] No proto pointer", stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%d] No proto pointer", stream_id);
return CURLE_FAILED_INIT;
}
switch(frame->hd.type) {
case NGHTTP2_DATA:
rbuflen = Curl_bufq_len(&stream->recvbuf);
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] FRAME[DATA len=%zu pad=%zu], "
"buffered=%zu, window=%d/%d",
stream_id, frame->hd.length, frame->data.padlen, rbuflen,
nghttp2_session_get_stream_effective_recv_data_length(
ctx->h2, stream->id),
nghttp2_session_get_stream_effective_local_window_size(
ctx->h2, stream->id)));
CURL_TRC_CF(data, cf, "[h2sid=%d] FRAME[DATA len=%zu pad=%zu], "
"buffered=%zu, window=%d/%d",
stream_id, frame->hd.length, frame->data.padlen, rbuflen,
nghttp2_session_get_stream_effective_recv_data_length(
ctx->h2, stream->id),
nghttp2_session_get_stream_effective_local_window_size(
ctx->h2, stream->id));
/* If !body started on this stream, then receiving DATA is illegal. */
if(!stream->bodystarted) {
rv = nghttp2_submit_rst_stream(ctx->h2, NGHTTP2_FLAG_NONE,
@ -1010,7 +1010,7 @@ static CURLcode on_stream_frame(struct Curl_cfilter *cf,
}
break;
case NGHTTP2_HEADERS:
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] FRAME[HEADERS]", stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%d] FRAME[HEADERS]", stream_id);
if(stream->bodystarted) {
/* Only valid HEADERS after body started is trailer HEADERS. We
buffer them in on_header callback. */
@ -1033,12 +1033,12 @@ static CURLcode on_stream_frame(struct Curl_cfilter *cf,
if(result)
return result;
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] %zu header bytes",
stream_id, Curl_bufq_len(&stream->recvbuf)));
CURL_TRC_CF(data, cf, "[h2sid=%d] %zu header bytes",
stream_id, Curl_bufq_len(&stream->recvbuf));
drain_stream(cf, data, stream);
break;
case NGHTTP2_PUSH_PROMISE:
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] FRAME[PUSH_PROMISE]", stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%d] FRAME[PUSH_PROMISE]", stream_id);
rv = push_promise(cf, data, &frame->push_promise);
if(rv) { /* deny! */
DEBUGASSERT((rv > CURL_PUSH_OK) && (rv <= CURL_PUSH_ERROROUT));
@ -1048,14 +1048,14 @@ static CURLcode on_stream_frame(struct Curl_cfilter *cf,
if(nghttp2_is_fatal(rv))
return CURLE_SEND_ERROR;
else if(rv == CURL_PUSH_ERROROUT) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] fail in PUSH_PROMISE received",
stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%d] fail in PUSH_PROMISE received",
stream_id);
return CURLE_RECV_ERROR;
}
}
break;
case NGHTTP2_RST_STREAM:
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] FRAME[RST]", stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%d] FRAME[RST]", stream_id);
stream->closed = TRUE;
stream->reset = TRUE;
stream->send_closed = TRUE;
@ -1063,18 +1063,17 @@ static CURLcode on_stream_frame(struct Curl_cfilter *cf,
drain_stream(cf, data, stream);
break;
case NGHTTP2_WINDOW_UPDATE:
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] FRAME[WINDOW_UPDATE]", stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%d] FRAME[WINDOW_UPDATE]", stream_id);
if((data->req.keepon & KEEP_SEND_HOLD) &&
(data->req.keepon & KEEP_SEND)) {
data->req.keepon &= ~KEEP_SEND_HOLD;
drain_stream(cf, data, stream);
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] un-holding after win update",
stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%d] un-holding after win update",
stream_id);
}
break;
default:
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] FRAME[%x]",
stream_id, frame->hd.type));
CURL_TRC_CF(data, cf, "[h2sid=%d] FRAME[%x]", stream_id, frame->hd.type);
break;
}
return CURLE_OK;
@ -1095,19 +1094,19 @@ static int on_frame_recv(nghttp2_session *session, const nghttp2_frame *frame,
switch(frame->hd.type) {
case NGHTTP2_SETTINGS: {
uint32_t max_conn = ctx->max_concurrent_streams;
DEBUGF(LOG_CF(data, cf, "FRAME[SETTINGS]"));
CURL_TRC_CF(data, cf, "FRAME[SETTINGS]");
ctx->max_concurrent_streams = nghttp2_session_get_remote_settings(
session, NGHTTP2_SETTINGS_MAX_CONCURRENT_STREAMS);
ctx->enable_push = nghttp2_session_get_remote_settings(
session, NGHTTP2_SETTINGS_ENABLE_PUSH) != 0;
DEBUGF(LOG_CF(data, cf, "MAX_CONCURRENT_STREAMS == %d",
ctx->max_concurrent_streams));
DEBUGF(LOG_CF(data, cf, "ENABLE_PUSH == %s",
ctx->enable_push ? "TRUE" : "false"));
CURL_TRC_CF(data, cf, "MAX_CONCURRENT_STREAMS == %d",
ctx->max_concurrent_streams);
CURL_TRC_CF(data, cf, "ENABLE_PUSH == %s",
ctx->enable_push ? "TRUE" : "false");
if(data && max_conn != ctx->max_concurrent_streams) {
/* only signal change if the value actually changed */
DEBUGF(LOG_CF(data, cf, "MAX_CONCURRENT_STREAMS now %u",
ctx->max_concurrent_streams));
CURL_TRC_CF(data, cf, "MAX_CONCURRENT_STREAMS now %u",
ctx->max_concurrent_streams);
Curl_multi_connchanged(data->multi);
}
/* Since the initial stream window is 64K, a request might be on HOLD,
@ -1121,8 +1120,8 @@ static int on_frame_recv(nghttp2_session *session, const nghttp2_frame *frame,
data->req.keepon &= ~KEEP_SEND_HOLD;
if(stream) {
drain_stream(cf, data, stream);
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] un-holding after SETTINGS",
stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%d] un-holding after SETTINGS",
stream_id);
}
}
break;
@ -1132,26 +1131,25 @@ static int on_frame_recv(nghttp2_session *session, const nghttp2_frame *frame,
ctx->goaway_error = frame->goaway.error_code;
ctx->last_stream_id = frame->goaway.last_stream_id;
if(data) {
DEBUGF(LOG_CF(data, cf, "FRAME[GOAWAY, error=%d, last_stream=%u]",
ctx->goaway_error, ctx->last_stream_id));
CURL_TRC_CF(data, cf, "FRAME[GOAWAY, error=%d, last_stream=%u]",
ctx->goaway_error, ctx->last_stream_id);
infof(data, "received GOAWAY, error=%d, last_stream=%u",
ctx->goaway_error, ctx->last_stream_id);
Curl_multi_connchanged(data->multi);
}
break;
case NGHTTP2_WINDOW_UPDATE:
DEBUGF(LOG_CF(data, cf, "FRAME[WINDOW_UPDATE]"));
CURL_TRC_CF(data, cf, "FRAME[WINDOW_UPDATE]");
break;
default:
DEBUGF(LOG_CF(data, cf, "recv frame %x on 0", frame->hd.type));
CURL_TRC_CF(data, cf, "recv frame %x on 0", frame->hd.type);
}
return 0;
}
data_s = nghttp2_session_get_stream_user_data(session, stream_id);
if(!data_s) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] No Curl_easy associated",
stream_id));
CURL_TRC_CF(data, cf, "[h2sid=%d] No Curl_easy associated", stream_id);
return 0;
}
@ -1178,8 +1176,8 @@ static int on_data_chunk_recv(nghttp2_session *session, uint8_t flags,
/* Receiving a Stream ID not in the hash should not happen - unless
we have aborted a transfer artificially and there were more data
in the pipeline. Silently ignore. */
DEBUGF(LOG_CF(CF_DATA_CURRENT(cf), cf, "[h2sid=%d] Data for unknown",
stream_id));
CURL_TRC_CF(CF_DATA_CURRENT(cf), cf, "[h2sid=%d] Data for unknown",
stream_id);
/* consumed explicitly as no one will read it */
nghttp2_session_consume(session, stream_id, len);
return 0;
@ -1221,8 +1219,8 @@ static int on_stream_close(nghttp2_session *session, int32_t stream_id,
return 0;
}
stream = H2_STREAM_CTX(data_s);
DEBUGF(LOG_CF(data_s, cf, "[h2sid=%d] on_stream_close(), %s (err %d)",
stream_id, nghttp2_http2_strerror(error_code), error_code));
CURL_TRC_CF(data_s, cf, "[h2sid=%d] on_stream_close(), %s (err %d)",
stream_id, nghttp2_http2_strerror(error_code), error_code);
if(!stream)
return NGHTTP2_ERR_CALLBACK_FAILURE;
@ -1241,7 +1239,7 @@ static int on_stream_close(nghttp2_session *session, int32_t stream_id,
stream_id);
DEBUGASSERT(0);
}
DEBUGF(LOG_CF(data_s, cf, "[h2sid=%d] closed now", stream_id));
CURL_TRC_CF(data_s, cf, "[h2sid=%d] closed now", stream_id);
return 0;
}
@ -1258,7 +1256,7 @@ static int on_begin_headers(nghttp2_session *session,
return 0;
}
DEBUGF(LOG_CF(data_s, cf, "on_begin_headers() was called"));
CURL_TRC_CF(data_s, cf, "on_begin_headers() was called");
if(frame->hd.type != NGHTTP2_HEADERS) {
return 0;
@ -1365,10 +1363,8 @@ static int on_header(nghttp2_session *session, const nghttp2_frame *frame,
if(stream->bodystarted) {
/* This is a trailer */
DEBUGF(LOG_CF(data_s, cf, "[h2sid=%d] trailer: %.*s: %.*s",
stream->id,
(int)namelen, name,
(int)valuelen, value));
CURL_TRC_CF(data_s, cf, "[h2sid=%d] trailer: %.*s: %.*s",
stream->id, (int)namelen, name, (int)valuelen, value);
result = Curl_dynhds_add(&stream->resp_trailers,
(const char *)name, namelen,
(const char *)value, valuelen);
@ -1405,8 +1401,8 @@ static int on_header(nghttp2_session *session, const nghttp2_frame *frame,
if(CF_DATA_CURRENT(cf) != data_s)
Curl_expire(data_s, 0, EXPIRE_RUN_NOW);
DEBUGF(LOG_CF(data_s, cf, "[h2sid=%d] status: HTTP/2 %03d",
stream->id, stream->status_code));
CURL_TRC_CF(data_s, cf, "[h2sid=%d] status: HTTP/2 %03d",
stream->id, stream->status_code);
return 0;
}
@ -1429,10 +1425,8 @@ static int on_header(nghttp2_session *session, const nghttp2_frame *frame,
if(CF_DATA_CURRENT(cf) != data_s)
Curl_expire(data_s, 0, EXPIRE_RUN_NOW);
DEBUGF(LOG_CF(data_s, cf, "[h2sid=%d] header: %.*s: %.*s",
stream->id,
(int)namelen, name,
(int)valuelen, value));
CURL_TRC_CF(data_s, cf, "[h2sid=%d] header: %.*s: %.*s",
stream->id, (int)namelen, name, (int)valuelen, value);
return 0; /* 0 is successful */
}
@ -1478,9 +1472,9 @@ static ssize_t req_body_read_callback(nghttp2_session *session,
if(nread > 0 && stream->upload_left != -1)
stream->upload_left -= nread;
DEBUGF(LOG_CF(data_s, cf, "[h2sid=%d] req_body_read(len=%zu) left=%"
CURL_FORMAT_CURL_OFF_T " -> %zd, %d",
stream_id, length, stream->upload_left, nread, result));
CURL_TRC_CF(data_s, cf, "[h2sid=%d] req_body_read(len=%zu) left=%"
CURL_FORMAT_CURL_OFF_T " -> %zd, %d",
stream_id, length, stream->upload_left, nread, result);
if(stream->upload_left == 0)
*data_flags = NGHTTP2_DATA_FLAG_EOF;
@ -1553,7 +1547,7 @@ static CURLcode http2_data_done_send(struct Curl_cfilter *cf,
if(!ctx || !ctx->h2 || !stream)
goto out;
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] data done send", stream->id));
CURL_TRC_CF(data, cf, "[h2sid=%d] data done send", stream->id);
if(!stream->send_closed) {
stream->send_closed = TRUE;
if(stream->upload_left) {
@ -1578,8 +1572,8 @@ static ssize_t http2_handle_stream_close(struct Curl_cfilter *cf,
ssize_t rv = 0;
if(stream->error == NGHTTP2_REFUSED_STREAM) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] REFUSED_STREAM, try again on a new "
"connection", stream->id));
CURL_TRC_CF(data, cf, "[h2sid=%d] REFUSED_STREAM, try again on a new "
"connection", stream->id);
connclose(cf->conn, "REFUSED_STREAM"); /* don't use this anymore */
data->state.refused_stream = TRUE;
*err = CURLE_SEND_ERROR; /* trigger Curl_retry_request() later */
@ -1640,7 +1634,7 @@ static ssize_t http2_handle_stream_close(struct Curl_cfilter *cf,
rv = 0;
out:
DEBUGF(LOG_CF(data, cf, "handle_stream_close -> %zd, %d", rv, *err));
CURL_TRC_CF(data, cf, "handle_stream_close -> %zd, %d", rv, *err);
return rv;
}
@ -1697,8 +1691,7 @@ static CURLcode h2_progress_egress(struct Curl_cfilter *cf,
nghttp2_priority_spec pri_spec;
h2_pri_spec(data, &pri_spec);
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] Queuing PRIORITY",
stream->id));
CURL_TRC_CF(data, cf, "[h2sid=%d] Queuing PRIORITY", stream->id);
DEBUGASSERT(stream->id != -1);
rv = nghttp2_submit_priority(ctx->h2, NGHTTP2_FLAG_NONE,
stream->id, &pri_spec);
@ -1712,8 +1705,8 @@ static CURLcode h2_progress_egress(struct Curl_cfilter *cf,
out:
if(nghttp2_is_fatal(rv)) {
DEBUGF(LOG_CF(data, cf, "nghttp2_session_send error (%s)%d",
nghttp2_strerror(rv), rv));
CURL_TRC_CF(data, cf, "nghttp2_session_send error (%s)%d",
nghttp2_strerror(rv), rv);
return CURLE_SEND_ERROR;
}
return nw_out_flush(cf, data);
@ -1730,8 +1723,8 @@ static ssize_t stream_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
if(!Curl_bufq_is_empty(&stream->recvbuf)) {
nread = Curl_bufq_read(&stream->recvbuf,
(unsigned char *)buf, len, err);
DEBUGF(LOG_CF(data, cf, "recvbuf read(len=%zu) -> %zd, %d",
len, nread, *err));
CURL_TRC_CF(data, cf, "recvbuf read(len=%zu) -> %zd, %d",
len, nread, *err);
if(nread < 0)
goto out;
DEBUGASSERT(nread > 0);
@ -1739,13 +1732,13 @@ static ssize_t stream_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
if(nread < 0) {
if(stream->closed) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] returning CLOSE", stream->id));
CURL_TRC_CF(data, cf, "[h2sid=%d] returning CLOSE", stream->id);
nread = http2_handle_stream_close(cf, data, stream, err);
}
else if(stream->reset ||
(ctx->conn_closed && Curl_bufq_is_empty(&ctx->inbufq)) ||
(ctx->goaway && ctx->last_stream_id < stream->id)) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] returning ERR", stream->id));
CURL_TRC_CF(data, cf, "[h2sid=%d] returning ERR", stream->id);
*err = stream->bodystarted? CURLE_PARTIAL_FILE : CURLE_RECV_ERROR;
nread = -1;
}
@ -1756,8 +1749,7 @@ static ssize_t stream_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
}
out:
DEBUGF(LOG_CF(data, cf, "stream_recv(len=%zu) -> %zd, %d",
len, nread, *err));
CURL_TRC_CF(data, cf, "stream_recv(len=%zu) -> %zd, %d", len, nread, *err);
return nread;
}
@ -1771,8 +1763,8 @@ static CURLcode h2_progress_ingress(struct Curl_cfilter *cf,
/* Process network input buffer fist */
if(!Curl_bufq_is_empty(&ctx->inbufq)) {
DEBUGF(LOG_CF(data, cf, "Process %zu bytes in connection buffer",
Curl_bufq_len(&ctx->inbufq)));
CURL_TRC_CF(data, cf, "Process %zu bytes in connection buffer",
Curl_bufq_len(&ctx->inbufq));
if(h2_process_pending_input(cf, data, &result) < 0)
return result;
}
@ -1792,8 +1784,6 @@ static CURLcode h2_progress_ingress(struct Curl_cfilter *cf,
}
nread = Curl_bufq_slurp(&ctx->inbufq, nw_in_reader, cf, &result);
/* DEBUGF(LOG_CF(data, cf, "read %zu bytes nw data -> %zd, %d",
Curl_bufq_len(&ctx->inbufq), nread, result)); */
if(nread < 0) {
if(result != CURLE_AGAIN) {
failf(data, "Failed receiving HTTP2 data: %d(%s)", result,
@ -1872,8 +1862,7 @@ static ssize_t cf_h2_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
}
if(stream->closed) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] closed stream, set drain",
stream->id));
CURL_TRC_CF(data, cf, "[h2sid=%d] closed stream, set drain", stream->id);
drain_stream(cf, data, stream);
}
}
@ -1884,16 +1873,16 @@ out:
*err = result;
nread = -1;
}
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] cf_recv(len=%zu) -> %zd %d, "
"buffered=%zu, window=%d/%d, connection %d/%d",
stream->id, len, nread, *err,
Curl_bufq_len(&stream->recvbuf),
nghttp2_session_get_stream_effective_recv_data_length(
ctx->h2, stream->id),
nghttp2_session_get_stream_effective_local_window_size(
ctx->h2, stream->id),
nghttp2_session_get_local_window_size(ctx->h2),
HTTP2_HUGE_WINDOW_SIZE));
CURL_TRC_CF(data, cf, "[h2sid=%d] cf_recv(len=%zu) -> %zd %d, "
"buffered=%zu, window=%d/%d, connection %d/%d",
stream->id, len, nread, *err,
Curl_bufq_len(&stream->recvbuf),
nghttp2_session_get_stream_effective_recv_data_length(
ctx->h2, stream->id),
nghttp2_session_get_stream_effective_local_window_size(
ctx->h2, stream->id),
nghttp2_session_get_local_window_size(ctx->h2),
HTTP2_HUGE_WINDOW_SIZE);
CF_DATA_RESTORE(cf, save);
return nread;
@ -1974,8 +1963,8 @@ static ssize_t h2_submit(struct stream_ctx **pstream,
h2_pri_spec(data, &pri_spec);
DEBUGF(LOG_CF(data, cf, "send request allowed %d",
nghttp2_session_check_request_allowed(ctx->h2)));
CURL_TRC_CF(data, cf, "send request allowed %d",
nghttp2_session_check_request_allowed(ctx->h2));
switch(data->state.httpreq) {
case HTTPREQ_POST:
@ -2002,15 +1991,15 @@ static ssize_t h2_submit(struct stream_ctx **pstream,
Curl_safefree(nva);
if(stream_id < 0) {
DEBUGF(LOG_CF(data, cf, "send: nghttp2_submit_request error (%s)%u",
nghttp2_strerror(stream_id), stream_id));
CURL_TRC_CF(data, cf, "send: nghttp2_submit_request error (%s)%u",
nghttp2_strerror(stream_id), stream_id);
*err = CURLE_SEND_ERROR;
nwritten = -1;
goto out;
}
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) submit %s",
stream_id, len, data->state.url));
CURL_TRC_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) submit %s",
stream_id, len, data->state.url);
infof(data, "Using Stream ID: %u", stream_id);
stream->id = stream_id;
stream->local_window_size = H2_STREAM_WINDOW_SIZE;
@ -2042,8 +2031,8 @@ static ssize_t h2_submit(struct stream_ctx **pstream,
}
out:
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] submit -> %zd, %d",
stream? stream->id : -1, nwritten, *err));
CURL_TRC_CF(data, cf, "[h2sid=%d] submit -> %zd, %d",
stream? stream->id : -1, nwritten, *err);
*pstream = stream;
Curl_h1_req_parse_free(&h1);
Curl_dynhds_free(&h2_headers);
@ -2155,19 +2144,19 @@ static ssize_t cf_h2_send(struct Curl_cfilter *cf, struct Curl_easy *data,
/* H2 flow window exhaustion. We need to HOLD upload until we get
* a WINDOW_UPDATE from the server. */
data->req.keepon |= KEEP_SEND_HOLD;
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] holding send as remote flow "
"window is exhausted", stream->id));
CURL_TRC_CF(data, cf, "[h2sid=%d] holding send as remote flow "
"window is exhausted", stream->id);
}
/* Whatever the cause, we need to return CURL_EAGAIN for this call.
* We have unwritten state that needs us being invoked again and EAGAIN
* is the only way to ensure that. */
stream->upload_blocked_len = nwritten;
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) BLOCK: win %u/%zu "
"blocked_len=%zu",
stream->id, len,
nghttp2_session_get_remote_window_size(ctx->h2), rwin,
nwritten));
CURL_TRC_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) BLOCK: win %u/%zu "
"blocked_len=%zu",
stream->id, len,
nghttp2_session_get_remote_window_size(ctx->h2), rwin,
nwritten);
*err = CURLE_AGAIN;
nwritten = -1;
goto out;
@ -2179,7 +2168,7 @@ static ssize_t cf_h2_send(struct Curl_cfilter *cf, struct Curl_easy *data,
nwritten = http2_handle_stream_close(cf, data, stream, err);
}
else {
DEBUGF(LOG_CF(data, cf, "send: nothing to do in this session"));
CURL_TRC_CF(data, cf, "send: nothing to do in this session");
*err = CURLE_HTTP2;
nwritten = -1;
}
@ -2187,24 +2176,24 @@ static ssize_t cf_h2_send(struct Curl_cfilter *cf, struct Curl_easy *data,
out:
if(stream) {
DEBUGF(LOG_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) -> %zd, %d, "
"upload_left=%" CURL_FORMAT_CURL_OFF_T ", "
"h2 windows %d-%d (stream-conn), "
"buffers %zu-%zu (stream-conn)",
stream->id, len, nwritten, *err,
(ssize_t)stream->upload_left,
nghttp2_session_get_stream_remote_window_size(
ctx->h2, stream->id),
nghttp2_session_get_remote_window_size(ctx->h2),
Curl_bufq_len(&stream->sendbuf),
Curl_bufq_len(&ctx->outbufq)));
CURL_TRC_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) -> %zd, %d, "
"upload_left=%" CURL_FORMAT_CURL_OFF_T ", "
"h2 windows %d-%d (stream-conn), "
"buffers %zu-%zu (stream-conn)",
stream->id, len, nwritten, *err,
(ssize_t)stream->upload_left,
nghttp2_session_get_stream_remote_window_size(
ctx->h2, stream->id),
nghttp2_session_get_remote_window_size(ctx->h2),
Curl_bufq_len(&stream->sendbuf),
Curl_bufq_len(&ctx->outbufq));
}
else {
DEBUGF(LOG_CF(data, cf, "cf_send(len=%zu) -> %zd, %d, "
"connection-window=%d, nw_send_buffer(%zu)",
len, nwritten, *err,
nghttp2_session_get_remote_window_size(ctx->h2),
Curl_bufq_len(&ctx->outbufq)));
CURL_TRC_CF(data, cf, "cf_send(len=%zu) -> %zd, %d, "
"connection-window=%d, nw_send_buffer(%zu)",
len, nwritten, *err,
nghttp2_session_get_remote_window_size(ctx->h2),
Curl_bufq_len(&ctx->outbufq));
}
CF_DATA_RESTORE(cf, save);
return nwritten;
@ -2421,8 +2410,8 @@ static bool cf_h2_is_alive(struct Curl_cfilter *cf,
CF_DATA_SAVE(save, cf, data);
result = (ctx && ctx->h2 && http2_connisalive(cf, data, input_pending));
DEBUGF(LOG_CF(data, cf, "conn alive -> %d, input_pending=%d",
result, *input_pending));
CURL_TRC_CF(data, cf, "conn alive -> %d, input_pending=%d",
result, *input_pending);
CF_DATA_RESTORE(cf, save);
return result;
}
@ -2473,7 +2462,7 @@ static CURLcode cf_h2_query(struct Curl_cfilter *cf,
struct Curl_cftype Curl_cft_nghttp2 = {
"HTTP/2",
CF_TYPE_MULTIPLEX,
CURL_LOG_DEFAULT,
CURL_LOG_LVL_NONE,
cf_h2_destroy,
cf_h2_connect,
cf_h2_close,

12
lib/http_proxy.c
View file

@ -69,7 +69,7 @@ static CURLcode http_proxy_cf_connect(struct Curl_cfilter *cf,
return CURLE_OK;
}
DEBUGF(LOG_CF(data, cf, "connect"));
CURL_TRC_CF(data, cf, "connect");
connect_sub:
result = cf->next->cft->do_connect(cf->next, data, blocking, done);
if(result || !*done)
@ -86,7 +86,7 @@ connect_sub:
case CURL_HTTP_VERSION_NONE:
case CURL_HTTP_VERSION_1_0:
case CURL_HTTP_VERSION_1_1:
DEBUGF(LOG_CF(data, cf, "installing subfilter for HTTP/1.1"));
CURL_TRC_CF(data, cf, "installing subfilter for HTTP/1.1");
infof(data, "CONNECT tunnel: HTTP/1.%d negotiated",
(alpn == CURL_HTTP_VERSION_1_0)? 0 : 1);
result = Curl_cf_h1_proxy_insert_after(cf, data);
@ -96,7 +96,7 @@ connect_sub:
break;
#ifdef USE_NGHTTP2
case CURL_HTTP_VERSION_2:
DEBUGF(LOG_CF(data, cf, "installing subfilter for HTTP/2"));
CURL_TRC_CF(data, cf, "installing subfilter for HTTP/2");
infof(data, "CONNECT tunnel: HTTP/2 negotiated");
result = Curl_cf_h2_proxy_insert_after(cf, data);
if(result)
@ -105,7 +105,7 @@ connect_sub:
break;
#endif
default:
DEBUGF(LOG_CF(data, cf, "installing subfilter for default HTTP/1.1"));
CURL_TRC_CF(data, cf, "installing subfilter for default HTTP/1.1");
infof(data, "CONNECT tunnel: unsupported ALPN(%d) negotiated", alpn);
result = CURLE_COULDNT_CONNECT;
goto out;
@ -156,7 +156,7 @@ static void http_proxy_cf_destroy(struct Curl_cfilter *cf,
struct cf_proxy_ctx *ctx = cf->ctx;
(void)data;
DEBUGF(LOG_CF(data, cf, "destroy"));
CURL_TRC_CF(data, cf, "destroy");
free(ctx);
}
@ -165,7 +165,7 @@ static void http_proxy_cf_close(struct Curl_cfilter *cf,
{
struct cf_proxy_ctx *ctx = cf->ctx;
DEBUGF(LOG_CF(data, cf, "close"));
CURL_TRC_CF(data, cf, "close");
cf->connected = FALSE;
if(ctx->cf_protocol) {
struct Curl_cfilter *f;

1
lib/rand.c
View file

@ -36,6 +36,7 @@ uint32_t arc4random(void);
#endif
#include <curl/curl.h>
#include "urldata.h"
#include "vtls/vtls.h"
#include "sendf.h"
#include "timeval.h"

2
lib/sendf.h
View file

@ -26,7 +26,7 @@
#include "curl_setup.h"
#include "curl_log.h"
#include "curl_trc.h"
#define CLIENTWRITE_BODY (1<<0)

8
lib/url.c
View file

@ -1494,13 +1494,7 @@ void Curl_verboseconnect(struct Curl_easy *data,
{
if(data->set.verbose)
infof(data, "Connected to %s (%s) port %u",
#ifndef CURL_DISABLE_PROXY
conn->bits.socksproxy ? conn->socks_proxy.host.dispname :
conn->bits.httpproxy ? conn->http_proxy.host.dispname :
#endif
conn->bits.conn_to_host ? conn->conn_to_host.dispname :
conn->host.dispname,
conn->primary_ip, conn->port);
CURL_CONN_HOST_DISPNAME(conn), conn->primary_ip, conn->port);
}
#endif

12
lib/urldata.h
View file

@ -1076,6 +1076,18 @@ struct connectdata {
unsigned char gssapi_delegation; /* inherited from set.gssapi_delegation */
};
#ifndef CURL_DISABLE_PROXY
#define CURL_CONN_HOST_DISPNAME(c) \
((c)->bits.socksproxy ? (c)->socks_proxy.host.dispname : \
(c)->bits.httpproxy ? (c)->http_proxy.host.dispname : \
(c)->bits.conn_to_host ? (c)->conn_to_host.dispname : \
(c)->host.dispname)
#else
#define CURL_CONN_HOST_DISPNAME(c) \
(c)->bits.conn_to_host ? (c)->conn_to_host.dispname : \
(c)->host.dispname)
#endif
/* The end of connectdata. */
/*

64
lib/vquic/curl_msh3.c
View file

@ -30,7 +30,7 @@
#include "timeval.h"
#include "multiif.h"
#include "sendf.h"
#include "curl_log.h"
#include "curl_trc.h"
#include "cfilters.h"
#include "cf-socket.h"
#include "connect.h"
@ -173,7 +173,7 @@ static CURLcode h3_data_setup(struct Curl_cfilter *cf,
msh3_lock_initialize(&stream->recv_lock);
Curl_bufq_init2(&stream->recvbuf, H3_STREAM_CHUNK_SIZE,
H3_STREAM_RECV_CHUNKS, BUFQ_OPT_SOFT_LIMIT);
DEBUGF(LOG_CF(data, cf, "data setup"));
CURL_TRC_CF(data, cf, "data setup");
return CURLE_OK;
}
@ -183,7 +183,7 @@ static void h3_data_done(struct Curl_cfilter *cf, struct Curl_easy *data)
(void)cf;
if(stream) {
DEBUGF(LOG_CF(data, cf, "easy handle is done"));
CURL_TRC_CF(data, cf, "easy handle is done");
Curl_bufq_free(&stream->recvbuf);
free(stream);
H3_STREAM_LCTX(data) = NULL;
@ -235,7 +235,7 @@ static void MSH3_CALL msh3_conn_connected(MSH3_CONNECTION *Connection,
struct Curl_easy *data = CF_DATA_CURRENT(cf);
(void)Connection;
DEBUGF(LOG_CF(data, cf, "[MSH3] connected"));
CURL_TRC_CF(data, cf, "[MSH3] connected");
ctx->handshake_succeeded = true;
ctx->connected = true;
ctx->handshake_complete = true;
@ -249,7 +249,7 @@ static void MSH3_CALL msh3_conn_shutdown_complete(MSH3_CONNECTION *Connection,
struct Curl_easy *data = CF_DATA_CURRENT(cf);
(void)Connection;
DEBUGF(LOG_CF(data, cf, "[MSH3] shutdown complete"));
CURL_TRC_CF(data, cf, "[MSH3] shutdown complete");
ctx->connected = false;
ctx->handshake_complete = true;
}
@ -474,18 +474,18 @@ static ssize_t recv_closed_stream(struct Curl_cfilter *cf,
if(stream->reset) {
failf(data, "HTTP/3 stream reset by server");
*err = CURLE_PARTIAL_FILE;
DEBUGF(LOG_CF(data, cf, "cf_recv, was reset -> %d", *err));
CURL_TRC_CF(data, cf, "cf_recv, was reset -> %d", *err);
goto out;
}
else if(stream->error3) {
failf(data, "HTTP/3 stream was not closed cleanly: (error %zd)",
(ssize_t)stream->error3);
*err = CURLE_HTTP3;
DEBUGF(LOG_CF(data, cf, "cf_recv, closed uncleanly -> %d", *err));
CURL_TRC_CF(data, cf, "cf_recv, closed uncleanly -> %d", *err);
goto out;
}
else {
DEBUGF(LOG_CF(data, cf, "cf_recv, closed ok -> %d", *err));
CURL_TRC_CF(data, cf, "cf_recv, closed ok -> %d", *err);
}
*err = CURLE_OK;
nread = 0;
@ -523,7 +523,7 @@ static ssize_t cf_msh3_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
return -1;
}
CF_DATA_SAVE(save, cf, data);
DEBUGF(LOG_CF(data, cf, "req: recv with %zu byte buffer", len));
CURL_TRC_CF(data, cf, "req: recv with %zu byte buffer", len);
msh3_lock_acquire(&stream->recv_lock);
@ -538,8 +538,8 @@ static ssize_t cf_msh3_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
if(!Curl_bufq_is_empty(&stream->recvbuf)) {
nread = Curl_bufq_read(&stream->recvbuf,
(unsigned char *)buf, len, err);
DEBUGF(LOG_CF(data, cf, "read recvbuf(len=%zu) -> %zd, %d",
len, nread, *err));
CURL_TRC_CF(data, cf, "read recvbuf(len=%zu) -> %zd, %d",
len, nread, *err);
if(nread < 0)
goto out;
if(stream->closed)
@ -550,7 +550,7 @@ static ssize_t cf_msh3_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
goto out;
}
else {
DEBUGF(LOG_CF(data, cf, "req: nothing here, call again"));
CURL_TRC_CF(data, cf, "req: nothing here, call again");
*err = CURLE_AGAIN;
}
@ -581,7 +581,7 @@ static ssize_t cf_msh3_send(struct Curl_cfilter *cf, struct Curl_easy *data,
/* Sizes must match for cast below to work" */
DEBUGASSERT(stream);
DEBUGF(LOG_CF(data, cf, "req: send %zu bytes", len));
CURL_TRC_CF(data, cf, "req: send %zu bytes", len);
if(!stream->req) {
/* The first send on the request contains the headers and possibly some
@ -630,7 +630,7 @@ static ssize_t cf_msh3_send(struct Curl_cfilter *cf, struct Curl_easy *data,
break;
}
DEBUGF(LOG_CF(data, cf, "req: send %zu headers", nheader));
CURL_TRC_CF(data, cf, "req: send %zu headers", nheader);
stream->req = MsH3RequestOpen(ctx->qconn, &msh3_request_if, data,
nva, nheader,
eos ? MSH3_REQUEST_FLAG_FIN :
@ -646,7 +646,7 @@ static ssize_t cf_msh3_send(struct Curl_cfilter *cf, struct Curl_easy *data,
}
else {
/* request is open */
DEBUGF(LOG_CF(data, cf, "req: send %zu body bytes", len));
CURL_TRC_CF(data, cf, "req: send %zu body bytes", len);
if(len > 0xFFFFFFFF) {
len = 0xFFFFFFFF;
}
@ -694,7 +694,7 @@ static int cf_msh3_get_select_socks(struct Curl_cfilter *cf,
drain_stream(cf, data);
}
}
DEBUGF(LOG_CF(data, cf, "select_sock -> %d", bitmap));
CURL_TRC_CF(data, cf, "select_sock -> %d", bitmap);
CF_DATA_RESTORE(cf, save);
return bitmap;
}
@ -711,8 +711,8 @@ static bool cf_msh3_data_pending(struct Curl_cfilter *cf,
(void)cf;
if(stream && stream->req) {
msh3_lock_acquire(&stream->recv_lock);
DEBUGF(LOG_CF((struct Curl_easy *)data, cf, "data pending = %zu",
Curl_bufq_len(&stream->recvbuf)));
CURL_TRC_CF((struct Curl_easy *)data, cf, "data pending = %zu",
Curl_bufq_len(&stream->recvbuf));
pending = !Curl_bufq_is_empty(&stream->recvbuf);
msh3_lock_release(&stream->recv_lock);
if(pending)
@ -774,7 +774,7 @@ static CURLcode cf_msh3_data_event(struct Curl_cfilter *cf,
h3_data_done(cf, data);
break;
case CF_CTRL_DATA_DONE_SEND:
DEBUGF(LOG_CF(data, cf, "req: send done"));
CURL_TRC_CF(data, cf, "req: send done");
if(stream) {
stream->upload_done = TRUE;
if(stream->req) {
@ -787,7 +787,7 @@ static CURLcode cf_msh3_data_event(struct Curl_cfilter *cf,
}
break;
case CF_CTRL_CONN_INFO_UPDATE:
DEBUGF(LOG_CF(data, cf, "req: update info"));
CURL_TRC_CF(data, cf, "req: update info");
cf_msh3_active(cf, data);
break;
default:
@ -813,17 +813,17 @@ static CURLcode cf_connect_start(struct Curl_cfilter *cf,
/* TODO: need a way to provide trust anchors to MSH3 */
#ifdef DEBUGBUILD
/* we need this for our test cases to run */
DEBUGF(LOG_CF(data, cf, "non-standard CA not supported, "
"switching off verifypeer in DEBUG mode"));
CURL_TRC_CF(data, cf, "non-standard CA not supported, "
"switching off verifypeer in DEBUG mode");
verify = 0;
#else
DEBUGF(LOG_CF(data, cf, "non-standard CA not supported, "
"attempting with built-in verification"));
CURL_TRC_CF(data, cf, "non-standard CA not supported, "
"attempting with built-in verification");
#endif
}
DEBUGF(LOG_CF(data, cf, "connecting to %s:%d (verify=%d)",
cf->conn->host.name, (int)cf->conn->remote_port, verify));
CURL_TRC_CF(data, cf, "connecting to %s:%d (verify=%d)",
cf->conn->host.name, (int)cf->conn->remote_port, verify);
ctx->api = MsH3ApiOpen();
if(!ctx->api) {
@ -888,7 +888,7 @@ static CURLcode cf_msh3_connect(struct Curl_cfilter *cf,
if(ctx->handshake_complete) {
ctx->handshake_at = Curl_now();
if(ctx->handshake_succeeded) {
DEBUGF(LOG_CF(data, cf, "handshake succeeded"));
CURL_TRC_CF(data, cf, "handshake succeeded");
cf->conn->bits.multiplex = TRUE; /* at least potentially multiplexed */
cf->conn->httpversion = 30;
cf->conn->bundle->multiuse = BUNDLE_MULTIPLEX;
@ -918,7 +918,7 @@ static void cf_msh3_close(struct Curl_cfilter *cf, struct Curl_easy *data)
CF_DATA_SAVE(save, cf, data);
if(ctx) {
DEBUGF(LOG_CF(data, cf, "destroying"));
CURL_TRC_CF(data, cf, "destroying");
if(ctx->qconn) {
MsH3ConnectionClose(ctx->qconn);
ctx->qconn = NULL;
@ -935,13 +935,13 @@ static void cf_msh3_close(struct Curl_cfilter *cf, struct Curl_easy *data)
*/
ctx->active = FALSE;
if(ctx->sock[SP_LOCAL] == cf->conn->sock[cf->sockindex]) {
DEBUGF(LOG_CF(data, cf, "cf_msh3_close(%d) active",
(int)ctx->sock[SP_LOCAL]));
CURL_TRC_CF(data, cf, "cf_msh3_close(%d) active",
(int)ctx->sock[SP_LOCAL]);
cf->conn->sock[cf->sockindex] = CURL_SOCKET_BAD;
}
else {
DEBUGF(LOG_CF(data, cf, "cf_socket_close(%d) no longer at "
"conn->sock[], discarding", (int)ctx->sock[SP_LOCAL]));
CURL_TRC_CF(data, cf, "cf_socket_close(%d) no longer at "
"conn->sock[], discarding", (int)ctx->sock[SP_LOCAL]);
ctx->sock[SP_LOCAL] = CURL_SOCKET_BAD;
}
if(cf->sockindex == FIRSTSOCKET)

156
lib/vquic/curl_ngtcp2.c
View file

@ -225,7 +225,7 @@ static CURLcode h3_data_setup(struct Curl_cfilter *cf,
stream->recv_buf_nonflow = 0;
H3_STREAM_LCTX(data) = stream;
DEBUGF(LOG_CF(data, cf, "data setup"));
CURL_TRC_CF(data, cf, "data setup");
return CURLE_OK;
}
@ -235,8 +235,7 @@ static void h3_data_done(struct Curl_cfilter *cf, struct Curl_easy *data)
(void)cf;
if(stream) {
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"] easy handle is done",
stream->id));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] easy handle is done", stream->id);
Curl_bufq_free(&stream->sendbuf);
Curl_bufq_free(&stream->recvbuf);
free(stream);
@ -544,15 +543,15 @@ static CURLcode quic_init_ssl(struct Curl_cfilter *cf,
gnutls_session_set_ptr(ctx->gtls->session, &ctx->conn_ref);
if(ngtcp2_crypto_gnutls_configure_client_session(ctx->gtls->session) != 0) {
DEBUGF(LOG_CF(data, cf,
"ngtcp2_crypto_gnutls_configure_client_session failed\n"));
CURL_TRC_CF(data, cf,
"ngtcp2_crypto_gnutls_configure_client_session failed\n");
return CURLE_QUIC_CONNECT_ERROR;
}
rc = gnutls_priority_set_direct(ctx->gtls->session, QUIC_PRIORITY, NULL);
if(rc < 0) {
DEBUGF(LOG_CF(data, cf, "gnutls_priority_set_direct failed: %s\n",
gnutls_strerror(rc)));
CURL_TRC_CF(data, cf, "gnutls_priority_set_direct failed: %s\n",
gnutls_strerror(rc));
return CURLE_QUIC_CONNECT_ERROR;
}
@ -728,8 +727,8 @@ static void report_consumed_data(struct Curl_cfilter *cf,
}
}
if(consumed > 0) {
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] consumed %zu DATA bytes",
stream->id, consumed));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] consumed %zu DATA bytes",
stream->id, consumed);
ngtcp2_conn_extend_max_stream_offset(ctx->qconn, stream->id,
consumed);
ngtcp2_conn_extend_max_offset(ctx->qconn, consumed);
@ -751,8 +750,8 @@ static int cb_recv_stream_data(ngtcp2_conn *tconn, uint32_t flags,
nconsumed =
nghttp3_conn_read_stream(ctx->h3conn, stream_id, buf, buflen, fin);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] read_stream(len=%zu) -> %zd",
stream_id, buflen, nconsumed));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] read_stream(len=%zu) -> %zd",
stream_id, buflen, nconsumed);
if(nconsumed < 0) {
ngtcp2_ccerr_set_application_error(
&ctx->last_error,
@ -810,8 +809,8 @@ static int cb_stream_close(ngtcp2_conn *tconn, uint32_t flags,
rv = nghttp3_conn_close_stream(ctx->h3conn, stream3_id,
app_error_code);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] quic close(err=%"
PRIu64 ") -> %d", stream3_id, app_error_code, rv));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] quic close(err=%"
PRIu64 ") -> %d", stream3_id, app_error_code, rv);
if(rv) {
ngtcp2_ccerr_set_application_error(
&ctx->last_error, nghttp3_err_infer_quic_app_error_code(rv), NULL, 0);
@ -835,7 +834,7 @@ static int cb_stream_reset(ngtcp2_conn *tconn, int64_t stream_id,
(void)data;
rv = nghttp3_conn_shutdown_stream_read(ctx->h3conn, stream_id);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] reset -> %d", stream_id, rv));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] reset -> %d", stream_id, rv);
if(rv) {
return NGTCP2_ERR_CALLBACK_FAILURE;
}
@ -1064,8 +1063,6 @@ static int cf_ngtcp2_get_select_socks(struct Curl_cfilter *cf,
stream && nghttp3_conn_is_stream_writable(ctx->h3conn, stream->id))
rv |= GETSOCK_WRITESOCK(0);
/* DEBUGF(LOG_CF(data, cf, "get_select_socks -> %x (sock=%d)",
rv, (int)socks[0])); */
CF_DATA_RESTORE(cf, save);
return rv;
}
@ -1102,8 +1099,8 @@ static int cb_h3_stream_close(nghttp3_conn *conn, int64_t stream_id,
if(!stream)
return 0;
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] h3 close(err=%" PRId64 ")",
stream_id, app_error_code));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] h3 close(err=%" PRId64 ")",
stream_id, app_error_code);
stream->closed = TRUE;
stream->error3 = app_error_code;
if(app_error_code == NGHTTP3_H3_INTERNAL_ERROR) {
@ -1133,9 +1130,6 @@ static CURLcode write_resp_raw(struct Curl_cfilter *cf,
return CURLE_RECV_ERROR;
}
nwritten = Curl_bufq_write(&stream->recvbuf, mem, memlen, &result);
/* DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] add recvbuf(len=%zu) "
"-> %zd, %d", stream->id, memlen, nwritten, result));
*/
if(nwritten < 0) {
return result;
}
@ -1204,8 +1198,8 @@ static int cb_h3_end_headers(nghttp3_conn *conn, int64_t stream_id,
return -1;
}
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] end_headers(status_code=%d",
stream_id, stream->status_code));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] end_headers(status_code=%d",
stream_id, stream->status_code);
if(stream->status_code / 100 != 1) {
stream->resp_hds_complete = TRUE;
}
@ -1244,8 +1238,7 @@ static int cb_h3_recv_header(nghttp3_conn *conn, int64_t stream_id,
return -1;
ncopy = msnprintf(line, sizeof(line), "HTTP/3 %03d \r\n",
stream->status_code);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] status: %s",
stream_id, line));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] status: %s", stream_id, line);
result = write_resp_raw(cf, data, line, ncopy, FALSE);
if(result) {
return -1;
@ -1253,9 +1246,9 @@ static int cb_h3_recv_header(nghttp3_conn *conn, int64_t stream_id,
}
else {
/* store as an HTTP1-style header */
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] header: %.*s: %.*s",
stream_id, (int)h3name.len, h3name.base,
(int)h3val.len, h3val.base));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] header: %.*s: %.*s",
stream_id, (int)h3name.len, h3name.base,
(int)h3val.len, h3val.base);
result = write_resp_raw(cf, data, h3name.base, h3name.len, FALSE);
if(result) {
return -1;
@ -1307,7 +1300,7 @@ static int cb_h3_reset_stream(nghttp3_conn *conn, int64_t stream_id,
rv = ngtcp2_conn_shutdown_stream_write(ctx->qconn, 0, stream_id,
app_error_code);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] reset -> %d", stream_id, rv));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] reset -> %d", stream_id, rv);
if(rv && rv != NGTCP2_ERR_STREAM_NOT_FOUND) {
return NGTCP2_ERR_CALLBACK_FAILURE;
}
@ -1405,8 +1398,8 @@ static ssize_t recv_closed_stream(struct Curl_cfilter *cf,
failf(data,
"HTTP/3 stream %" PRId64 " reset by server", stream->id);
*err = CURLE_PARTIAL_FILE;
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, was reset -> %d",
stream->id, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, was reset -> %d",
stream->id, *err);
goto out;
}
else if(stream->error3 != NGHTTP3_H3_NO_ERROR) {
@ -1414,8 +1407,8 @@ static ssize_t recv_closed_stream(struct Curl_cfilter *cf,
"HTTP/3 stream %" PRId64 " was not closed cleanly: "
"(err %"PRId64")", stream->id, stream->error3);
*err = CURLE_HTTP3;
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed uncleanly"
" -> %d", stream->id, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed uncleanly"
" -> %d", stream->id, *err);
goto out;
}
@ -1425,13 +1418,13 @@ static ssize_t recv_closed_stream(struct Curl_cfilter *cf,
" all response header fields, treated as error",
stream->id);
*err = CURLE_HTTP3;
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed incomplete"
" -> %d", stream->id, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed incomplete"
" -> %d", stream->id, *err);
goto out;
}
else {
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed ok"
" -> %d", stream->id, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed ok"
" -> %d", stream->id, *err);
}
*err = CURLE_OK;
nread = 0;
@ -1469,8 +1462,8 @@ static ssize_t cf_ngtcp2_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
if(!Curl_bufq_is_empty(&stream->recvbuf)) {
nread = Curl_bufq_read(&stream->recvbuf,
(unsigned char *)buf, len, err);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] read recvbuf(len=%zu) "
"-> %zd, %d", stream->id, len, nread, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] read recvbuf(len=%zu) "
"-> %zd, %d", stream->id, len, nread, *err);
if(nread < 0)
goto out;
report_consumed_data(cf, data, nread);
@ -1486,8 +1479,8 @@ static ssize_t cf_ngtcp2_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
if(nread < 0 && !Curl_bufq_is_empty(&stream->recvbuf)) {
nread = Curl_bufq_read(&stream->recvbuf,
(unsigned char *)buf, len, err);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] read recvbuf(len=%zu) "
"-> %zd, %d", stream->id, len, nread, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] read recvbuf(len=%zu) "
"-> %zd, %d", stream->id, len, nread, *err);
if(nread < 0)
goto out;
report_consumed_data(cf, data, nread);
@ -1517,8 +1510,8 @@ out:
nread = -1;
}
}
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv(len=%zu) -> %zd, %d",
stream? stream->id : -1, len, nread, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv(len=%zu) -> %zd, %d",
stream? stream->id : -1, len, nread, *err);
CF_DATA_RESTORE(cf, save);
return nread;
}
@ -1555,8 +1548,7 @@ static int cb_h3_acked_req_body(nghttp3_conn *conn, int64_t stream_id,
(data->req.keepon & KEEP_SEND)) {
data->req.keepon &= ~KEEP_SEND_HOLD;
h3_drain_stream(cf, data);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] unpausing acks",
stream_id));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] unpausing acks", stream_id);
}
}
return 0;
@ -1613,18 +1605,18 @@ cb_h3_read_req_body(nghttp3_conn *conn, int64_t stream_id,
}
else if(!nwritten) {
/* Not EOF, and nothing to give, we signal WOULDBLOCK. */
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] read req body -> AGAIN",
stream->id));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] read req body -> AGAIN",
stream->id);
return NGHTTP3_ERR_WOULDBLOCK;
}
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] read req body -> "
"%d vecs%s with %zu (buffered=%zu, left=%"
CURL_FORMAT_CURL_OFF_T ")",
stream->id, (int)nvecs,
*pflags == NGHTTP3_DATA_FLAG_EOF?" EOF":"",
nwritten, Curl_bufq_len(&stream->sendbuf),
stream->upload_left));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] read req body -> "
"%d vecs%s with %zu (buffered=%zu, left=%"
CURL_FORMAT_CURL_OFF_T ")",
stream->id, (int)nvecs,
*pflags == NGHTTP3_DATA_FLAG_EOF?" EOF":"",
nwritten, Curl_bufq_len(&stream->sendbuf),
stream->upload_left);
return (nghttp3_ssize)nvecs;
}
@ -1723,12 +1715,12 @@ static ssize_t h3_stream_open(struct Curl_cfilter *cf,
if(rc) {
switch(rc) {
case NGHTTP3_ERR_CONN_CLOSING:
DEBUGF(LOG_CF(data, cf, "h3sid[%"PRId64"] failed to send, "
"connection is closing", stream->id));
CURL_TRC_CF(data, cf, "h3sid[%"PRId64"] failed to send, "
"connection is closing", stream->id);
break;
default:
DEBUGF(LOG_CF(data, cf, "h3sid[%"PRId64"] failed to send -> %d (%s)",
stream->id, rc, ngtcp2_strerror(rc)));
CURL_TRC_CF(data, cf, "h3sid[%"PRId64"] failed to send -> %d (%s)",
stream->id, rc, ngtcp2_strerror(rc));
break;
}
*err = CURLE_SEND_ERROR;
@ -1737,8 +1729,8 @@ static ssize_t h3_stream_open(struct Curl_cfilter *cf,
}
infof(data, "Using HTTP/3 Stream ID: %" PRId64, stream->id);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] opened for %s",
stream->id, data->state.url));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] opened for %s",
stream->id, data->state.url);
out:
free(nva);
@ -1773,7 +1765,7 @@ static ssize_t cf_ngtcp2_send(struct Curl_cfilter *cf, struct Curl_easy *data,
if(!stream || stream->id < 0) {
sent = h3_stream_open(cf, data, buf, len, err);
if(sent < 0) {
DEBUGF(LOG_CF(data, cf, "failed to open stream -> %d", *err));
CURL_TRC_CF(data, cf, "failed to open stream -> %d", *err);
goto out;
}
}
@ -1799,9 +1791,9 @@ static ssize_t cf_ngtcp2_send(struct Curl_cfilter *cf, struct Curl_easy *data,
}
else {
sent = Curl_bufq_write(&stream->sendbuf, buf, len, err);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_send, add to "
"sendbuf(len=%zu) -> %zd, %d",
stream->id, len, sent, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_send, add to "
"sendbuf(len=%zu) -> %zd, %d",
stream->id, len, sent, *err);
if(sent < 0) {
goto out;
}
@ -1821,9 +1813,9 @@ static ssize_t cf_ngtcp2_send(struct Curl_cfilter *cf, struct Curl_easy *data,
* "written" into our various internal connection buffers.
* We put the stream upload on HOLD, until this gets ACKed. */
stream->upload_blocked_len = sent;
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_send(len=%zu), "
"%zu bytes in flight -> EGAIN", stream->id, len,
stream->sendbuf_len_in_flight));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_send(len=%zu), "
"%zu bytes in flight -> EGAIN", stream->id, len,
stream->sendbuf_len_in_flight);
*err = CURLE_AGAIN;
sent = -1;
data->req.keepon |= KEEP_SEND_HOLD;
@ -1835,8 +1827,8 @@ out:
*err = result;
sent = -1;
}
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_send(len=%zu) -> %zd, %d",
stream? stream->id : -1, len, sent, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_send(len=%zu) -> %zd, %d",
stream? stream->id : -1, len, sent, *err);
CF_DATA_RESTORE(cf, save);
return sent;
}
@ -1913,8 +1905,8 @@ static CURLcode recv_pkt(const unsigned char *pkt, size_t pktlen,
rv = ngtcp2_conn_read_pkt(ctx->qconn, &path, &pi, pkt, pktlen, pktx->ts);
if(rv) {
DEBUGF(LOG_CF(pktx->data, pktx->cf, "ingress, read_pkt -> %s",
ngtcp2_strerror(rv)));
CURL_TRC_CF(pktx->data, pktx->cf, "ingress, read_pkt -> %s",
ngtcp2_strerror(rv));
if(!ctx->last_error.error_code) {
if(rv == NGTCP2_ERR_CRYPTO) {
ngtcp2_ccerr_set_tls_alert(&ctx->last_error,
@ -2129,8 +2121,6 @@ static CURLcode cf_progress_egress(struct Curl_cfilter *cf,
/* add the next packet to send, if any, to our buffer */
nread = Curl_bufq_sipn(&ctx->q.sendbuf, max_payload_size,
read_pkt_to_send, pktx, &curlcode);
/* DEBUGF(LOG_CF(data, cf, "sip packet(maxlen=%zu) -> %zd, %d",
max_payload_size, nread, curlcode)); */
if(nread < 0) {
if(curlcode != CURLE_AGAIN)
return curlcode;
@ -2305,7 +2295,7 @@ static void cf_ngtcp2_close(struct Curl_cfilter *cf, struct Curl_easy *data)
ngtcp2_tstamp ts;
ngtcp2_ssize rc;
DEBUGF(LOG_CF(data, cf, "close"));
CURL_TRC_CF(data, cf, "close");
ts = timestamp();
rc = ngtcp2_conn_write_connection_close(ctx->qconn, NULL, /* path */
NULL, /* pkt_info */
@ -2329,7 +2319,7 @@ static void cf_ngtcp2_destroy(struct Curl_cfilter *cf, struct Curl_easy *data)
struct cf_call_data save;
CF_DATA_SAVE(save, cf, data);
DEBUGF(LOG_CF(data, cf, "destroy"));
CURL_TRC_CF(data, cf, "destroy");
if(ctx) {
cf_ngtcp2_ctx_clear(ctx);
free(ctx);
@ -2460,7 +2450,7 @@ static CURLcode cf_ngtcp2_connect(struct Curl_cfilter *cf,
if(ctx->reconnect_at.tv_sec && Curl_timediff(now, ctx->reconnect_at) < 0) {
/* Not time yet to attempt the next connect */
DEBUGF(LOG_CF(data, cf, "waiting for reconnect time"));
CURL_TRC_CF(data, cf, "waiting for reconnect time");
goto out;
}
@ -2484,11 +2474,11 @@ static CURLcode cf_ngtcp2_connect(struct Curl_cfilter *cf,
if(ngtcp2_conn_get_handshake_completed(ctx->qconn)) {
ctx->handshake_at = now;
DEBUGF(LOG_CF(data, cf, "handshake complete after %dms",
(int)Curl_timediff(now, ctx->started_at)));
CURL_TRC_CF(data, cf, "handshake complete after %dms",
(int)Curl_timediff(now, ctx->started_at));
result = qng_verify_peer(cf, data);
if(!result) {
DEBUGF(LOG_CF(data, cf, "peer verified"));
CURL_TRC_CF(data, cf, "peer verified");
cf->connected = TRUE;
cf->conn->alpn = CURL_HTTP_VERSION_3;
*done = TRUE;
@ -2510,8 +2500,8 @@ out:
*/
int reconn_delay_ms = 200;
DEBUGF(LOG_CF(data, cf, "connect, remote closed, reconnect after %dms",
reconn_delay_ms));
CURL_TRC_CF(data, cf, "connect, remote closed, reconnect after %dms",
reconn_delay_ms);
Curl_conn_cf_close(cf->next, data);
cf_ngtcp2_ctx_clear(ctx);
result = Curl_conn_cf_connect(cf->next, data, FALSE, done);
@ -2538,7 +2528,7 @@ out:
if(!result && ctx->qconn) {
result = check_and_set_expiry(cf, data, &pktx);
}
DEBUGF(LOG_CF(data, cf, "connect -> %d, done=%d", result, *done));
CURL_TRC_CF(data, cf, "connect -> %d, done=%d", result, *done);
CF_DATA_RESTORE(cf, save);
return result;
}
@ -2562,7 +2552,7 @@ static CURLcode cf_ngtcp2_query(struct Curl_cfilter *cf,
INT_MAX : (int)rp->initial_max_streams_bidi;
else /* not arrived yet? */
*pres1 = Curl_multi_max_concurrent_streams(data->multi);
DEBUGF(LOG_CF(data, cf, "query max_conncurrent -> %d", *pres1));
CURL_TRC_CF(data, cf, "query max_conncurrent -> %d", *pres1);
CF_DATA_RESTORE(cf, save);
return CURLE_OK;
}

163
lib/vquic/curl_quiche.c
View file

@ -217,11 +217,10 @@ static void stream_send_suspend(struct Curl_cfilter *cf,
data->req.keepon |= KEEP_SEND_HOLD;
++ctx->sends_on_hold;
if(H3_STREAM_ID(data) >= 0)
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"] suspend sending",
H3_STREAM_ID(data)));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] suspend sending",
H3_STREAM_ID(data));
else
DEBUGF(LOG_CF(data, cf, "[%s] suspend sending",
data->state.url));
CURL_TRC_CF(data, cf, "[%s] suspend sending", data->state.url);
}
}
@ -234,11 +233,10 @@ static void stream_send_resume(struct Curl_cfilter *cf,
data->req.keepon &= ~KEEP_SEND_HOLD;
--ctx->sends_on_hold;
if(H3_STREAM_ID(data) >= 0)
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"] resume sending",
H3_STREAM_ID(data)));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] resume sending",
H3_STREAM_ID(data));
else
DEBUGF(LOG_CF(data, cf, "[%s] resume sending",
data->state.url));
CURL_TRC_CF(data, cf, "[%s] resume sending", data->state.url);
Curl_expire(data, 0, EXPIRE_RUN_NOW);
}
}
@ -277,7 +275,7 @@ static CURLcode h3_data_setup(struct Curl_cfilter *cf,
stream->id = -1;
Curl_bufq_initp(&stream->recvbuf, &ctx->stream_bufcp,
H3_STREAM_RECV_CHUNKS, BUFQ_OPT_SOFT_LIMIT);
DEBUGF(LOG_CF(data, cf, "data setup"));
CURL_TRC_CF(data, cf, "data setup");
return CURLE_OK;
}
@ -288,8 +286,7 @@ static void h3_data_done(struct Curl_cfilter *cf, struct Curl_easy *data)
(void)cf;
if(stream) {
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"] easy handle is done",
stream->id));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] easy handle is done", stream->id);
if(stream_send_is_suspended(data)) {
data->req.keepon &= ~KEEP_SEND_HOLD;
--ctx->sends_on_hold;
@ -397,10 +394,10 @@ static int cb_each_header(uint8_t *name, size_t name_len,
result = write_resp_raw(x->cf, x->data, "\r\n", 2);
}
if(result) {
DEBUGF(LOG_CF(x->data, x->cf,
"[h3sid=%"PRId64"][HEADERS][%.*s: %.*s] error %d",
stream? stream->id : -1, (int)name_len, name,
(int)value_len, value, result));
CURL_TRC_CF(x->data, x->cf,
"[h3sid=%"PRId64"][HEADERS][%.*s: %.*s] error %d",
stream? stream->id : -1, (int)name_len, name,
(int)value_len, value, result);
}
return result;
}
@ -455,8 +452,8 @@ static CURLcode cf_recv_body(struct Curl_cfilter *cf,
stream_resp_read, &cb_ctx, &result);
if(nwritten < 0 && result != CURLE_AGAIN) {
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"] recv_body error %zd",
stream->id, nwritten));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] recv_body error %zd",
stream->id, nwritten);
failf(data, "Error %d in HTTP/3 response body for stream[%"PRId64"]",
result, stream->id);
stream->closed = TRUE;
@ -514,7 +511,7 @@ static CURLcode h3_process_event(struct Curl_cfilter *cf,
rc, stream3_id);
return CURLE_RECV_ERROR;
}
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"][HEADERS]", stream3_id));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"][HEADERS]", stream3_id);
break;
case QUICHE_H3_EVENT_DATA:
@ -524,7 +521,7 @@ static CURLcode h3_process_event(struct Curl_cfilter *cf,
break;
case QUICHE_H3_EVENT_RESET:
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"][RESET]", stream3_id));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"][RESET]", stream3_id);
stream->closed = TRUE;
stream->reset = TRUE;
stream->send_closed = TRUE;
@ -532,7 +529,7 @@ static CURLcode h3_process_event(struct Curl_cfilter *cf,
break;
case QUICHE_H3_EVENT_FINISHED:
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"][FINISHED]", stream3_id));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"][FINISHED]", stream3_id);
if(!stream->resp_hds_complete) {
result = write_resp_raw(cf, data, "\r\n", 2);
if(result)
@ -544,12 +541,12 @@ static CURLcode h3_process_event(struct Curl_cfilter *cf,
break;
case QUICHE_H3_EVENT_GOAWAY:
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"][GOAWAY]", stream3_id));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"][GOAWAY]", stream3_id);
break;
default:
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"] recv, unhandled event %d",
stream3_id, quiche_h3_event_type(ev)));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] recv, unhandled event %d",
stream3_id, quiche_h3_event_type(ev));
break;
}
return result;
@ -571,26 +568,25 @@ static CURLcode cf_poll_events(struct Curl_cfilter *cf,
break;
}
else if(stream3_id < 0) {
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"] error poll: %"PRId64,
stream? stream->id : -1, stream3_id));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] error poll: %"PRId64,
stream? stream->id : -1, stream3_id);
return CURLE_HTTP3;
}
sdata = get_stream_easy(cf, data, stream3_id);
if(!sdata) {
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"] discard event %s for "
"unknown [h3sid=%"PRId64"]",
stream? stream->id : -1, cf_ev_name(ev),
stream3_id));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] discard event %s for "
"unknown [h3sid=%"PRId64"]",
stream? stream->id : -1, cf_ev_name(ev), stream3_id);
}
else {
result = h3_process_event(cf, sdata, stream3_id, ev);
drain_stream(cf, sdata);
if(result) {
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"] error processing event %s "
"for [h3sid=%"PRId64"] -> %d",
stream? stream->id : -1, cf_ev_name(ev),
stream3_id, result));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] error processing event %s "
"for [h3sid=%"PRId64"] -> %d",
stream? stream->id : -1, cf_ev_name(ev),
stream3_id, result);
if(data == sdata) {
/* Only report this error to the caller if it is about the
* transfer we were called with. Otherwise we fail a transfer
@ -633,7 +629,7 @@ static CURLcode recv_pkt(const unsigned char *pkt, size_t pktlen,
&recv_info);
if(nread < 0) {
if(QUICHE_ERR_DONE == nread) {
DEBUGF(LOG_CF(r->data, r->cf, "ingress, quiche is DONE"));
CURL_TRC_CF(r->data, r->cf, "ingress, quiche is DONE");
return CURLE_OK;
}
else if(QUICHE_ERR_TLS_FAIL == nread) {
@ -650,8 +646,8 @@ static CURLcode recv_pkt(const unsigned char *pkt, size_t pktlen,
}
}
else if((size_t)nread < pktlen) {
DEBUGF(LOG_CF(r->data, r->cf, "ingress, quiche only read %zd/%zu bytes",
nread, pktlen));
CURL_TRC_CF(r->data, r->cf, "ingress, quiche only read %zd/%zu bytes",
nread, pktlen);
}
return CURLE_OK;
@ -742,9 +738,6 @@ static CURLcode cf_flush_egress(struct Curl_cfilter *cf,
/* add the next packet to send, if any, to our buffer */
nread = Curl_bufq_sipn(&ctx->q.sendbuf, 0,
read_pkt_to_send, &readx, &result);
/* DEBUGF(LOG_CF(data, cf, "sip packet(maxlen=%zu) -> %zd, %d",
(size_t)0, nread, result)); */
if(nread < 0) {
if(result != CURLE_AGAIN)
return result;
@ -795,8 +788,8 @@ static ssize_t recv_closed_stream(struct Curl_cfilter *cf,
failf(data,
"HTTP/3 stream %" PRId64 " reset by server", stream->id);
*err = stream->resp_got_header? CURLE_PARTIAL_FILE : CURLE_RECV_ERROR;
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, was reset -> %d",
stream->id, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, was reset -> %d",
stream->id, *err);
}
else if(!stream->resp_got_header) {
failf(data,
@ -805,14 +798,14 @@ static ssize_t recv_closed_stream(struct Curl_cfilter *cf,
stream->id);
/* *err = CURLE_PARTIAL_FILE; */
*err = CURLE_RECV_ERROR;
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed incomplete"
" -> %d", stream->id, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed incomplete"
" -> %d", stream->id, *err);
}
else {
*err = CURLE_OK;
nread = 0;
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed ok"
" -> %d", stream->id, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed ok"
" -> %d", stream->id, *err);
}
return nread;
}
@ -833,14 +826,14 @@ static ssize_t cf_quiche_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
if(!Curl_bufq_is_empty(&stream->recvbuf)) {
nread = Curl_bufq_read(&stream->recvbuf,
(unsigned char *)buf, len, err);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] read recvbuf(len=%zu) "
"-> %zd, %d", stream->id, len, nread, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] read recvbuf(len=%zu) "
"-> %zd, %d", stream->id, len, nread, *err);
if(nread < 0)
goto out;
}
if(cf_process_ingress(cf, data)) {
DEBUGF(LOG_CF(data, cf, "cf_recv, error on ingress"));
CURL_TRC_CF(data, cf, "cf_recv, error on ingress");
*err = CURLE_RECV_ERROR;
nread = -1;
goto out;
@ -850,8 +843,8 @@ static ssize_t cf_quiche_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
if(nread < 0 && !Curl_bufq_is_empty(&stream->recvbuf)) {
nread = Curl_bufq_read(&stream->recvbuf,
(unsigned char *)buf, len, err);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] read recvbuf(len=%zu) "
"-> %zd, %d", stream->id, len, nread, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] read recvbuf(len=%zu) "
"-> %zd, %d", stream->id, len, nread, *err);
if(nread < 0)
goto out;
}
@ -878,16 +871,16 @@ static ssize_t cf_quiche_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
out:
result = cf_flush_egress(cf, data);
if(result) {
DEBUGF(LOG_CF(data, cf, "cf_recv, flush egress failed"));
CURL_TRC_CF(data, cf, "cf_recv, flush egress failed");
*err = result;
nread = -1;
}
if(nread > 0)
ctx->data_recvd += nread;
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"] cf_recv(total=%"
CURL_FORMAT_CURL_OFF_T ") -> %zd, %d",
stream ? stream->id : (int64_t)0,
ctx->data_recvd, nread, *err));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] cf_recv(total=%"
CURL_FORMAT_CURL_OFF_T ") -> %zd, %d",
stream ? stream->id : (int64_t)0,
ctx->data_recvd, nread, *err);
return nread;
}
@ -975,16 +968,16 @@ static ssize_t h3_open_stream(struct Curl_cfilter *cf,
if(QUICHE_H3_ERR_STREAM_BLOCKED == stream3_id) {
/* quiche seems to report this error if the connection window is
* exhausted. Which happens frequently and intermittent. */
DEBUGF(LOG_CF(data, cf, "send_request(%s) rejected with BLOCKED",
data->state.url));
CURL_TRC_CF(data, cf, "send_request(%s) rejected with BLOCKED",
data->state.url);
stream_send_suspend(cf, data);
*err = CURLE_AGAIN;
nwritten = -1;
goto out;
}
else {
DEBUGF(LOG_CF(data, cf, "send_request(%s) -> %" PRId64,
data->state.url, stream3_id));
CURL_TRC_CF(data, cf, "send_request(%s) -> %" PRId64,
data->state.url, stream3_id);
}
*err = CURLE_SEND_ERROR;
nwritten = -1;
@ -998,8 +991,8 @@ static ssize_t h3_open_stream(struct Curl_cfilter *cf,
stream->reset = FALSE;
infof(data, "Using HTTP/3 Stream ID: %" PRId64, stream3_id);
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] opened for %s",
stream3_id, data->state.url));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] opened for %s",
stream3_id, data->state.url);
out:
free(nva);
@ -1037,8 +1030,8 @@ static ssize_t cf_quiche_send(struct Curl_cfilter *cf, struct Curl_easy *data,
/* TODO: we seem to be blocked on flow control and should HOLD
* sending. But when do we open again? */
if(!quiche_conn_stream_writable(ctx->qconn, stream->id, len)) {
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] send_body(len=%zu) "
"-> window exhausted", stream->id, len));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] send_body(len=%zu) "
"-> window exhausted", stream->id, len);
stream_send_suspend(cf, data);
}
*err = CURLE_AGAIN;
@ -1046,15 +1039,15 @@ static ssize_t cf_quiche_send(struct Curl_cfilter *cf, struct Curl_easy *data,
goto out;
}
else if(nwritten == QUICHE_H3_TRANSPORT_ERR_FINAL_SIZE) {
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] send_body(len=%zu) "
"-> exceeds size", stream->id, len));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] send_body(len=%zu) "
"-> exceeds size", stream->id, len);
*err = CURLE_SEND_ERROR;
nwritten = -1;
goto out;
}
else if(nwritten < 0) {
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] send_body(len=%zu) "
"-> quiche err %zd", stream->id, len, nwritten));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] send_body(len=%zu) "
"-> quiche err %zd", stream->id, len, nwritten);
*err = CURLE_SEND_ERROR;
nwritten = -1;
goto out;
@ -1068,9 +1061,9 @@ static ssize_t cf_quiche_send(struct Curl_cfilter *cf, struct Curl_easy *data,
if(stream->upload_left == 0)
stream->send_closed = TRUE;
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] send body(len=%zu, "
"left=%" CURL_FORMAT_CURL_OFF_T ") -> %zd",
stream->id, len, stream->upload_left, nwritten));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] send body(len=%zu, "
"left=%" CURL_FORMAT_CURL_OFF_T ") -> %zd",
stream->id, len, stream->upload_left, nwritten);
*err = CURLE_OK;
}
}
@ -1081,8 +1074,8 @@ out:
*err = result;
nwritten = -1;
}
DEBUGF(LOG_CF(data, cf, "[h3sid=%" PRId64 "] cf_send(len=%zu) -> %zd, %d",
stream? stream->id : -1, len, nwritten, *err));
CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_send(len=%zu) -> %zd, %d",
stream? stream->id : -1, len, nwritten, *err);
return nwritten;
}
@ -1171,15 +1164,15 @@ static CURLcode cf_quiche_data_event(struct Curl_cfilter *cf,
stream->upload_left = 0;
body[0] = 'X';
sent = cf_quiche_send(cf, data, body, 0, &result);
DEBUGF(LOG_CF(data, cf, "[h3sid=%"PRId64"] DONE_SEND -> %zd, %d",
stream->id, sent, result));
CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] DONE_SEND -> %zd, %d",
stream->id, sent, result);
}
break;
}
case CF_CTRL_DATA_IDLE:
result = cf_flush_egress(cf, data);
if(result)
DEBUGF(LOG_CF(data, cf, "data idle, flush egress -> %d", result));
CURL_TRC_CF(data, cf, "data idle, flush egress -> %d", result);
break;
default:
break;
@ -1210,7 +1203,7 @@ static CURLcode cf_verify_peer(struct Curl_cfilter *cf,
goto out;
}
else
DEBUGF(LOG_CF(data, cf, "Skipped certificate verification"));
CURL_TRC_CF(data, cf, "Skipped certificate verification");
ctx->h3config = quiche_h3_config_new();
if(!ctx->h3config) {
@ -1357,8 +1350,8 @@ static CURLcode cf_connect_start(struct Curl_cfilter *cf,
offset += 1 + alpn_len;
}
DEBUGF(LOG_CF(data, cf, "Sent QUIC client Initial, ALPN: %s",
alpn_protocols + 1));
CURL_TRC_CF(data, cf, "Sent QUIC client Initial, ALPN: %s",
alpn_protocols + 1);
}
return CURLE_OK;
@ -1389,7 +1382,7 @@ static CURLcode cf_quiche_connect(struct Curl_cfilter *cf,
if(ctx->reconnect_at.tv_sec && Curl_timediff(now, ctx->reconnect_at) < 0) {
/* Not time yet to attempt the next connect */
DEBUGF(LOG_CF(data, cf, "waiting for reconnect time"));
CURL_TRC_CF(data, cf, "waiting for reconnect time");
goto out;
}
@ -1412,12 +1405,12 @@ static CURLcode cf_quiche_connect(struct Curl_cfilter *cf,
goto out;
if(quiche_conn_is_established(ctx->qconn)) {
DEBUGF(LOG_CF(data, cf, "handshake complete after %dms",
(int)Curl_timediff(now, ctx->started_at)));
CURL_TRC_CF(data, cf, "handshake complete after %dms",
(int)Curl_timediff(now, ctx->started_at));
ctx->handshake_at = now;
result = cf_verify_peer(cf, data);
if(!result) {
DEBUGF(LOG_CF(data, cf, "peer verified"));
CURL_TRC_CF(data, cf, "peer verified");
cf->connected = TRUE;
cf->conn->alpn = CURL_HTTP_VERSION_3;
*done = TRUE;
@ -1436,8 +1429,8 @@ static CURLcode cf_quiche_connect(struct Curl_cfilter *cf,
*/
int reconn_delay_ms = 200;
DEBUGF(LOG_CF(data, cf, "connect, remote closed, reconnect after %dms",
reconn_delay_ms));
CURL_TRC_CF(data, cf, "connect, remote closed, reconnect after %dms",
reconn_delay_ms);
Curl_conn_cf_close(cf->next, data);
cf_quiche_ctx_clear(ctx);
result = Curl_conn_cf_connect(cf->next, data, FALSE, done);
@ -1503,7 +1496,7 @@ static CURLcode cf_quiche_query(struct Curl_cfilter *cf,
max_streams += quiche_conn_peer_streams_left_bidi(ctx->qconn);
}
*pres1 = (max_streams > INT_MAX)? INT_MAX : (int)max_streams;
DEBUGF(LOG_CF(data, cf, "query: MAX_CONCURRENT -> %d", *pres1));
CURL_TRC_CF(data, cf, "query: MAX_CONCURRENT -> %d", *pres1);
return CURLE_OK;
}
case CF_QUERY_CONNECT_REPLY_MS:

32
lib/vquic/vquic.c
View file

@ -43,7 +43,7 @@
#include "bufq.h"
#include "dynbuf.h"
#include "cfilters.h"
#include "curl_log.h"
#include "curl_trc.h"
#include "curl_msh3.h"
#include "curl_ngtcp2.h"
#include "curl_quiche.h"
@ -253,11 +253,9 @@ CURLcode vquic_flush(struct Curl_cfilter *cf, struct Curl_easy *data,
blen = qctx->split_len;
}
DEBUGF(LOG_CF(data, cf, "vquic_send(len=%zu, gso=%zu)",
blen, gsolen));
result = vquic_send_packets(cf, data, qctx, buf, blen, gsolen, &sent);
DEBUGF(LOG_CF(data, cf, "vquic_send(len=%zu, gso=%zu) -> %d, sent=%zu",
blen, gsolen, result, sent));
CURL_TRC_CF(data, cf, "vquic_send(len=%zu, gso=%zu) -> %d, sent=%zu",
blen, gsolen, result, sent);
if(result) {
if(result == CURLE_AGAIN) {
Curl_bufq_skip(&qctx->sendbuf, sent);
@ -288,9 +286,9 @@ CURLcode vquic_send_tail_split(struct Curl_cfilter *cf, struct Curl_easy *data,
qctx->split_len = Curl_bufq_len(&qctx->sendbuf) - tail_len;
qctx->split_gsolen = gsolen;
qctx->gsolen = tail_gsolen;
DEBUGF(LOG_CF(data, cf, "vquic_send_tail_split: [%zu gso=%zu][%zu gso=%zu]",
qctx->split_len, qctx->split_gsolen,
tail_len, qctx->gsolen));
CURL_TRC_CF(data, cf, "vquic_send_tail_split: [%zu gso=%zu][%zu gso=%zu]",
qctx->split_len, qctx->split_gsolen,
tail_len, qctx->gsolen);
return vquic_flush(cf, data, qctx);
}
@ -330,7 +328,7 @@ static CURLcode recvmmsg_packets(struct Curl_cfilter *cf,
;
if(mcount == -1) {
if(SOCKERRNO == EAGAIN || SOCKERRNO == EWOULDBLOCK) {
DEBUGF(LOG_CF(data, cf, "ingress, recvmmsg -> EAGAIN"));
CURL_TRC_CF(data, cf, "ingress, recvmmsg -> EAGAIN");
goto out;
}
if(!cf->connected && SOCKERRNO == ECONNREFUSED) {
@ -349,7 +347,7 @@ static CURLcode recvmmsg_packets(struct Curl_cfilter *cf,
goto out;
}
DEBUGF(LOG_CF(data, cf, "recvmmsg() -> %d packets", mcount));
CURL_TRC_CF(data, cf, "recvmmsg() -> %d packets", mcount);
pkts += mcount;
for(i = 0; i < mcount; ++i) {
total_nread += mmsg[i].msg_len;
@ -362,8 +360,8 @@ static CURLcode recvmmsg_packets(struct Curl_cfilter *cf,
}
out:
DEBUGF(LOG_CF(data, cf, "recvd %zu packets with %zu bytes -> %d",
pkts, total_nread, result));
CURL_TRC_CF(data, cf, "recvd %zu packets with %zu bytes -> %d",
pkts, total_nread, result);
return result;
}
@ -425,8 +423,8 @@ static CURLcode recvmsg_packets(struct Curl_cfilter *cf,
}
out:
DEBUGF(LOG_CF(data, cf, "recvd %zu packets with %zu bytes -> %d",
pkts, total_nread, result));
CURL_TRC_CF(data, cf, "recvd %zu packets with %zu bytes -> %d",
pkts, total_nread, result);
return result;
}
@ -454,7 +452,7 @@ static CURLcode recvfrom_packets(struct Curl_cfilter *cf,
;
if(nread == -1) {
if(SOCKERRNO == EAGAIN || SOCKERRNO == EWOULDBLOCK) {
DEBUGF(LOG_CF(data, cf, "ingress, recvfrom -> EAGAIN"));
CURL_TRC_CF(data, cf, "ingress, recvfrom -> EAGAIN");
goto out;
}
if(!cf->connected && SOCKERRNO == ECONNREFUSED) {
@ -482,8 +480,8 @@ static CURLcode recvfrom_packets(struct Curl_cfilter *cf,
}
out:
DEBUGF(LOG_CF(data, cf, "recvd %zu packets with %zu bytes -> %d",
pkts, total_nread, result));
CURL_TRC_CF(data, cf, "recvd %zu packets with %zu bytes -> %d",
pkts, total_nread, result);
return result;
}
#endif /* !HAVE_SENDMMSG && !HAVE_SENDMSG */

7
lib/vssh/libssh2.c
View file

@ -2534,7 +2534,8 @@ static CURLcode ssh_statemach_act(struct Curl_easy *data, bool *block)
if(from > size) {
failf(data, "Offset (%"
CURL_FORMAT_CURL_OFF_T ") was beyond file size (%"
CURL_FORMAT_CURL_OFF_T ")", from, attrs.filesize);
CURL_FORMAT_CURL_OFF_T ")", from,
(curl_off_t)attrs.filesize);
return CURLE_BAD_DOWNLOAD_RESUME;
}
if(from > to) {
@ -2560,7 +2561,7 @@ static CURLcode ssh_statemach_act(struct Curl_easy *data, bool *block)
failf(data, "Offset (%"
CURL_FORMAT_CURL_OFF_T ") was beyond file size (%"
CURL_FORMAT_CURL_OFF_T ")",
data->state.resume_from, attrs.filesize);
data->state.resume_from, (curl_off_t)attrs.filesize);
return CURLE_BAD_DOWNLOAD_RESUME;
}
/* download from where? */
@ -2570,7 +2571,7 @@ static CURLcode ssh_statemach_act(struct Curl_easy *data, bool *block)
if((curl_off_t)attrs.filesize < data->state.resume_from) {
failf(data, "Offset (%" CURL_FORMAT_CURL_OFF_T
") was beyond file size (%" CURL_FORMAT_CURL_OFF_T ")",
data->state.resume_from, attrs.filesize);
data->state.resume_from, (curl_off_t)attrs.filesize);
return CURLE_BAD_DOWNLOAD_RESUME;
}
}

8
lib/vtls/mbedtls.c
View file

@ -165,8 +165,8 @@ static int bio_cf_write(void *bio, const unsigned char *buf, size_t blen)
DEBUGASSERT(data);
nwritten = Curl_conn_cf_send(cf->next, data, (char *)buf, blen, &result);
DEBUGF(LOG_CF(data, cf, "bio_cf_out_write(len=%zu) -> %zd, err=%d",
blen, nwritten, result));
CURL_TRC_CF(data, cf, "bio_cf_out_write(len=%zu) -> %zd, err=%d",
blen, nwritten, result);
if(nwritten < 0 && CURLE_AGAIN == result) {
nwritten = MBEDTLS_ERR_SSL_WANT_WRITE;
}
@ -186,8 +186,8 @@ static int bio_cf_read(void *bio, unsigned char *buf, size_t blen)
return 0;
nread = Curl_conn_cf_recv(cf->next, data, (char *)buf, blen, &result);
DEBUGF(LOG_CF(data, cf, "bio_cf_in_read(len=%zu) -> %zd, err=%d",
blen, nread, result));
CURL_TRC_CF(data, cf, "bio_cf_in_read(len=%zu) -> %zd, err=%d",
blen, nread, result);
if(nread < 0 && CURLE_AGAIN == result) {
nread = MBEDTLS_ERR_SSL_WANT_READ;
}

8
lib/vtls/openssl.c
View file

@ -722,8 +722,8 @@ static int bio_cf_out_write(BIO *bio, const char *buf, int blen)
DEBUGASSERT(data);
nwritten = Curl_conn_cf_send(cf->next, data, buf, blen, &result);
DEBUGF(LOG_CF(data, cf, "bio_cf_out_write(len=%d) -> %d, err=%d",
blen, (int)nwritten, result));
CURL_TRC_CF(data, cf, "bio_cf_out_write(len=%d) -> %d, err=%d",
blen, (int)nwritten, result);
BIO_clear_retry_flags(bio);
backend->io_result = result;
if(nwritten < 0) {
@ -749,8 +749,8 @@ static int bio_cf_in_read(BIO *bio, char *buf, int blen)
return 0;
nread = Curl_conn_cf_recv(cf->next, data, buf, blen, &result);
DEBUGF(LOG_CF(data, cf, "bio_cf_in_read(len=%d) -> %d, err=%d",
blen, (int)nread, result));
CURL_TRC_CF(data, cf, "bio_cf_in_read(len=%d) -> %d, err=%d",
blen, (int)nread, result);
BIO_clear_retry_flags(bio);
backend->io_result = result;
if(nread < 0) {

18
lib/vtls/rustls.c
View file

@ -104,10 +104,6 @@ read_cb(void *userdata, uint8_t *buf, uintptr_t len, uintptr_t *out_n)
ret = EINVAL;
}
*out_n = (int)nread;
/*
DEBUGF(LOG_CF(io_ctx->data, io_ctx->cf, "cf->next recv(len=%zu) -> %zd, %d",
len, nread, result));
*/
return ret;
}
@ -128,7 +124,7 @@ write_cb(void *userdata, const uint8_t *buf, uintptr_t len, uintptr_t *out_n)
}
*out_n = (int)nwritten;
/*
DEBUGF(LOG_CF(io_ctx->data, io_ctx->cf, "cf->next send(len=%zu) -> %zd, %d",
CURL_TRC_CFX(io_ctx->data, io_ctx->cf, "cf->next send(len=%zu) -> %zd, %d",
len, nwritten, result));
*/
return ret;
@ -267,8 +263,8 @@ cr_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
}
out:
DEBUGF(LOG_CF(data, cf, "cf_recv(len=%zu) -> %zd, %d",
plainlen, nread, *err));
CURL_TRC_CF(data, cf, "cf_recv(len=%zu) -> %zd, %d",
plainlen, nread, *err);
return nread;
}
@ -302,7 +298,7 @@ cr_send(struct Curl_cfilter *cf, struct Curl_easy *data,
DEBUGASSERT(backend);
rconn = backend->conn;
DEBUGF(LOG_CF(data, cf, "cf_send: %ld plain bytes", plainlen));
CURL_TRC_CF(data, cf, "cf_send: %ld plain bytes", plainlen);
io_ctx.cf = cf;
io_ctx.data = data;
@ -327,8 +323,8 @@ cr_send(struct Curl_cfilter *cf, struct Curl_easy *data,
io_error = rustls_connection_write_tls(rconn, write_cb, &io_ctx,
&tlswritten);
if(io_error == EAGAIN || io_error == EWOULDBLOCK) {
DEBUGF(LOG_CF(data, cf, "cf_send: EAGAIN after %zu bytes",
tlswritten_total));
CURL_TRC_CF(data, cf, "cf_send: EAGAIN after %zu bytes",
tlswritten_total);
*err = CURLE_AGAIN;
return -1;
}
@ -344,7 +340,7 @@ cr_send(struct Curl_cfilter *cf, struct Curl_easy *data,
*err = CURLE_WRITE_ERROR;
return -1;
}
DEBUGF(LOG_CF(data, cf, "cf_send: wrote %zu TLS bytes", tlswritten));
CURL_TRC_CF(data, cf, "cf_send: wrote %zu TLS bytes", tlswritten);
tlswritten_total += tlswritten;
}

40
lib/vtls/sectransp.c
View file

@ -845,8 +845,8 @@ static OSStatus bio_cf_in_read(SSLConnectionRef connection,
DEBUGASSERT(data);
nread = Curl_conn_cf_recv(cf->next, data, buf, *dataLength, &result);
DEBUGF(LOG_CF(data, cf, "bio_read(len=%zu) -> %zd, result=%d",
*dataLength, nread, result));
CURL_TRC_CF(data, cf, "bio_read(len=%zu) -> %zd, result=%d",
*dataLength, nread, result);
if(nread < 0) {
switch(result) {
case CURLE_OK:
@ -885,8 +885,8 @@ static OSStatus bio_cf_out_write(SSLConnectionRef connection,
DEBUGASSERT(data);
nwritten = Curl_conn_cf_send(cf->next, data, buf, *dataLength, &result);
DEBUGF(LOG_CF(data, cf, "bio_send(len=%zu) -> %zd, result=%d",
*dataLength, nwritten, result));
CURL_TRC_CF(data, cf, "bio_send(len=%zu) -> %zd, result=%d",
*dataLength, nwritten, result);
if(nwritten <= 0) {
if(result == CURLE_AGAIN) {
rtn = errSSLWouldBlock;
@ -1612,7 +1612,7 @@ static CURLcode sectransp_set_selected_ciphers(struct Curl_easy *data,
The message is a bit cryptic and longer than necessary but can be
understood by humans. */
failf(data, "SSL: cipher string \"%s\" contains unsupported cipher name"
" starting position %d and ending position %d",
" starting position %zd and ending position %zd",
ciphers,
cipher_start - ciphers,
cipher_end - ciphers);
@ -1663,7 +1663,7 @@ static CURLcode sectransp_connect_step1(struct Curl_cfilter *cf,
DEBUGASSERT(backend);
DEBUGF(LOG_CF(data, cf, "connect_step1"));
CURL_TRC_CF(data, cf, "connect_step1");
GetDarwinVersionNumber(&darwinver_maj, &darwinver_min);
#endif /* CURL_BUILD_MAC */
@ -2294,7 +2294,7 @@ static CURLcode verify_cert_buf(struct Curl_cfilter *cf,
/* This is not a PEM file, probably a certificate in DER format. */
rc = append_cert_to_array(data, certbuf, buflen, array);
if(rc != CURLE_OK) {
DEBUGF(LOG_CF(data, cf, "append_cert for CA failed"));
CURL_TRC_CF(data, cf, "append_cert for CA failed");
result = rc;
goto out;
}
@ -2308,7 +2308,7 @@ static CURLcode verify_cert_buf(struct Curl_cfilter *cf,
rc = append_cert_to_array(data, der, derlen, array);
free(der);
if(rc != CURLE_OK) {
DEBUGF(LOG_CF(data, cf, "append_cert for CA failed"));
CURL_TRC_CF(data, cf, "append_cert for CA failed");
result = rc;
goto out;
}
@ -2324,7 +2324,7 @@ static CURLcode verify_cert_buf(struct Curl_cfilter *cf,
goto out;
}
DEBUGF(LOG_CF(data, cf, "setting %d trust anchors", n));
CURL_TRC_CF(data, cf, "setting %d trust anchors", n);
ret = SecTrustSetAnchorCertificates(trust, array);
if(ret != noErr) {
failf(data, "SecTrustSetAnchorCertificates() returned error %d", ret);
@ -2346,11 +2346,11 @@ static CURLcode verify_cert_buf(struct Curl_cfilter *cf,
switch(trust_eval) {
case kSecTrustResultUnspecified:
/* what does this really mean? */
DEBUGF(LOG_CF(data, cf, "trust result: Unspecified"));
CURL_TRC_CF(data, cf, "trust result: Unspecified");
result = CURLE_OK;
goto out;
case kSecTrustResultProceed:
DEBUGF(LOG_CF(data, cf, "trust result: Proceed"));
CURL_TRC_CF(data, cf, "trust result: Proceed");
result = CURLE_OK;
goto out;
@ -2383,7 +2383,7 @@ static CURLcode verify_cert(struct Curl_cfilter *cf,
size_t buflen;
if(ca_info_blob) {
DEBUGF(LOG_CF(data, cf, "verify_peer, CA from config blob"));
CURL_TRC_CF(data, cf, "verify_peer, CA from config blob");
certbuf = (unsigned char *)malloc(ca_info_blob->len + 1);
if(!certbuf) {
return CURLE_OUT_OF_MEMORY;
@ -2393,7 +2393,7 @@ static CURLcode verify_cert(struct Curl_cfilter *cf,
certbuf[ca_info_blob->len]='\0';
}
else if(cafile) {
DEBUGF(LOG_CF(data, cf, "verify_peer, CA from file '%s'", cafile));
CURL_TRC_CF(data, cf, "verify_peer, CA from file '%s'", cafile);
if(read_cert(cafile, &certbuf, &buflen) < 0) {
failf(data, "SSL: failed to read or invalid CA certificate");
return CURLE_SSL_CACERT_BADFILE;
@ -2485,7 +2485,7 @@ static CURLcode pkp_pin_peer_pubkey(struct Curl_easy *data,
spkiHeaderLength = 23;
break;
default:
infof(data, "SSL: unhandled public key length: %d", pubkeylen);
infof(data, "SSL: unhandled public key length: %zu", pubkeylen);
#elif SECTRANSP_PINNEDPUBKEY_V2
default:
/* ecDSA secp256r1 pubkeylen == 91 header already included?
@ -2534,7 +2534,7 @@ static CURLcode sectransp_connect_step2(struct Curl_cfilter *cf,
|| ssl_connect_2_reading == connssl->connecting_state
|| ssl_connect_2_writing == connssl->connecting_state);
DEBUGASSERT(backend);
DEBUGF(LOG_CF(data, cf, "connect_step2"));
CURL_TRC_CF(data, cf, "connect_step2");
/* Here goes nothing: */
check_handshake:
@ -3001,7 +3001,7 @@ static CURLcode sectransp_connect_step3(struct Curl_cfilter *cf,
struct ssl_connect_data *connssl = cf->ctx;
CURLcode result;
DEBUGF(LOG_CF(data, cf, "connect_step3"));
CURL_TRC_CF(data, cf, "connect_step3");
/* There is no step 3!
* Well, okay, let's collect server certificates, and if verbose mode is on,
* let's print the details of the server certificates. */
@ -3110,7 +3110,7 @@ sectransp_connect_common(struct Curl_cfilter *cf, struct Curl_easy *data,
}
if(ssl_connect_done == connssl->connecting_state) {
DEBUGF(LOG_CF(data, cf, "connected"));
CURL_TRC_CF(data, cf, "connected");
connssl->state = ssl_connection_complete;
*done = TRUE;
}
@ -3157,7 +3157,7 @@ static void sectransp_close(struct Curl_cfilter *cf, struct Curl_easy *data)
DEBUGASSERT(backend);
if(backend->ssl_ctx) {
DEBUGF(LOG_CF(data, cf, "close"));
CURL_TRC_CF(data, cf, "close");
(void)SSLClose(backend->ssl_ctx);
#if CURL_BUILD_MAC_10_8 || CURL_BUILD_IOS
if(SSLCreateContext)
@ -3203,7 +3203,7 @@ static int sectransp_shutdown(struct Curl_cfilter *cf,
what = SOCKET_READABLE(Curl_conn_cf_get_socket(cf, data),
SSL_SHUTDOWN_TIMEOUT);
DEBUGF(LOG_CF(data, cf, "shutdown"));
CURL_TRC_CF(data, cf, "shutdown");
while(loop--) {
if(what < 0) {
/* anything that gets here is fatally bad */
@ -3265,7 +3265,7 @@ static bool sectransp_data_pending(struct Curl_cfilter *cf,
DEBUGASSERT(backend);
if(backend->ssl_ctx) { /* SSL is in use */
DEBUGF(LOG_CF((struct Curl_easy *)data, cf, "data_pending"));
CURL_TRC_CF((struct Curl_easy *)data, cf, "data_pending");
err = SSLGetBufferedReadSize(backend->ssl_ctx, &buffer);
if(err == noErr)
return buffer > 0UL;

6
lib/vtls/vtls.c
View file

@ -1596,7 +1596,7 @@ static ssize_t ssl_cf_recv(struct Curl_cfilter *cf,
/* eof */
*err = CURLE_OK;
}
DEBUGF(LOG_CF(data, cf, "cf_recv(len=%zu) -> %zd, %d", len, nread, *err));
CURL_TRC_CF(data, cf, "cf_recv(len=%zu) -> %zd, %d", len, nread, *err);
CF_DATA_RESTORE(cf, save);
return nread;
}
@ -1697,7 +1697,7 @@ static bool cf_ssl_is_alive(struct Curl_cfilter *cf, struct Curl_easy *data,
struct Curl_cftype Curl_cft_ssl = {
"SSL",
CF_TYPE_SSL,
CURL_LOG_DEFAULT,
CURL_LOG_LVL_NONE,
ssl_cf_destroy,
ssl_cf_connect,
ssl_cf_close,
@ -1715,7 +1715,7 @@ struct Curl_cftype Curl_cft_ssl = {
struct Curl_cftype Curl_cft_ssl_proxy = {
"SSL-PROXY",
CF_TYPE_SSL,
CURL_LOG_DEFAULT,
CURL_LOG_LVL_NONE,
ssl_cf_destroy,
ssl_cf_connect,
ssl_cf_close,

24
lib/vtls/wolfssl.c
View file

@ -290,8 +290,8 @@ static int bio_cf_out_write(WOLFSSL_BIO *bio, const char *buf, int blen)
DEBUGASSERT(data);
nwritten = Curl_conn_cf_send(cf->next, data, buf, blen, &result);
backend->io_result = result;
DEBUGF(LOG_CF(data, cf, "bio_write(len=%d) -> %zd, %d",
blen, nwritten, result));
CURL_TRC_CF(data, cf, "bio_write(len=%d) -> %zd, %d",
blen, nwritten, result);
wolfSSL_BIO_clear_retry_flags(bio);
if(nwritten < 0 && CURLE_AGAIN == result)
BIO_set_retry_read(bio);
@ -315,8 +315,7 @@ static int bio_cf_in_read(WOLFSSL_BIO *bio, char *buf, int blen)
nread = Curl_conn_cf_recv(cf->next, data, buf, blen, &result);
backend->io_result = result;
DEBUGF(LOG_CF(data, cf, "bio_read(len=%d) -> %zd, %d",
blen, nread, result));
CURL_TRC_CF(data, cf, "bio_read(len=%d) -> %zd, %d", blen, nread, result);
wolfSSL_BIO_clear_retry_flags(bio);
if(nread < 0 && CURLE_AGAIN == result)
BIO_set_retry_read(bio);
@ -1018,17 +1017,16 @@ static ssize_t wolfssl_send(struct Curl_cfilter *cf,
case SSL_ERROR_WANT_READ:
case SSL_ERROR_WANT_WRITE:
/* there's data pending, re-invoke SSL_write() */
DEBUGF(LOG_CF(data, cf, "wolfssl_send(len=%zu) -> AGAIN", len));
CURL_TRC_CF(data, cf, "wolfssl_send(len=%zu) -> AGAIN", len);
*curlcode = CURLE_AGAIN;
return -1;
default:
if(backend->io_result == CURLE_AGAIN) {
DEBUGF(LOG_CF(data, cf, "wolfssl_send(len=%zu) -> AGAIN", len));
CURL_TRC_CF(data, cf, "wolfssl_send(len=%zu) -> AGAIN", len);
*curlcode = CURLE_AGAIN;
return -1;
}
DEBUGF(LOG_CF(data, cf, "wolfssl_send(len=%zu) -> %d, %d",
len, rc, err));
CURL_TRC_CF(data, cf, "wolfssl_send(len=%zu) -> %d, %d", len, rc, err);
failf(data, "SSL write: %s, errno %d",
ERR_error_string(err, error_buffer),
SOCKERRNO);
@ -1036,7 +1034,7 @@ static ssize_t wolfssl_send(struct Curl_cfilter *cf,
return -1;
}
}
DEBUGF(LOG_CF(data, cf, "wolfssl_send(len=%zu) -> %d", len, rc));
CURL_TRC_CF(data, cf, "wolfssl_send(len=%zu) -> %d", len, rc);
return rc;
}
@ -1089,7 +1087,7 @@ static ssize_t wolfssl_recv(struct Curl_cfilter *cf,
switch(err) {
case SSL_ERROR_ZERO_RETURN: /* no more data */
DEBUGF(LOG_CF(data, cf, "wolfssl_recv(len=%zu) -> CLOSED", blen));
CURL_TRC_CF(data, cf, "wolfssl_recv(len=%zu) -> CLOSED", blen);
*curlcode = CURLE_OK;
return 0;
case SSL_ERROR_NONE:
@ -1098,12 +1096,12 @@ static ssize_t wolfssl_recv(struct Curl_cfilter *cf,
/* FALLTHROUGH */
case SSL_ERROR_WANT_WRITE:
/* there's data pending, re-invoke SSL_read() */
DEBUGF(LOG_CF(data, cf, "wolfssl_recv(len=%zu) -> AGAIN", blen));
CURL_TRC_CF(data, cf, "wolfssl_recv(len=%zu) -> AGAIN", blen);
*curlcode = CURLE_AGAIN;
return -1;
default:
if(backend->io_result == CURLE_AGAIN) {
DEBUGF(LOG_CF(data, cf, "wolfssl_recv(len=%zu) -> AGAIN", blen));
CURL_TRC_CF(data, cf, "wolfssl_recv(len=%zu) -> AGAIN", blen);
*curlcode = CURLE_AGAIN;
return -1;
}
@ -1113,7 +1111,7 @@ static ssize_t wolfssl_recv(struct Curl_cfilter *cf,
return -1;
}
}
DEBUGF(LOG_CF(data, cf, "wolfssl_recv(len=%zu) -> %d", blen, nread));
CURL_TRC_CF(data, cf, "wolfssl_recv(len=%zu) -> %d", blen, nread);
return nread;
}