curl/lib/curl_trc.c

Ignoring revisions in .git-blame-ignore-revs. Click here to bypass and see the normal blame view.

332 lines
8.2 KiB
C
Raw Normal View History

/***************************************************************************
* _ _ ____ _
* 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
*
***************************************************************************/
#include "curl_setup.h"
#include <curl/curl.h>
#include "curl_trc.h"
#include "urldata.h"
#include "easyif.h"
#include "cfilters.h"
#include "timeval.h"
#include "multiif.h"
#include "strcase.h"
#include "cf-socket.h"
#include "connect.h"
#include "doh.h"
#include "http2.h"
#include "http_proxy.h"
#include "cf-h1-proxy.h"
#include "cf-h2-proxy.h"
#include "cf-haproxy.h"
#include "cf-https-connect.h"
#include "socks.h"
#include "strtok.h"
#include "vtls/vtls.h"
#include "vquic/vquic.h"
/* The last 3 #include files should be in this order */
#include "curl_printf.h"
#include "curl_memory.h"
#include "memdebug.h"
void Curl_debug(struct Curl_easy *data, curl_infotype type,
char *ptr, size_t size)
{
if(data->set.verbose) {
static const char s_infotype[CURLINFO_END][3] = {
"* ", "< ", "> ", "{ ", "} ", "{ ", "} " };
if(data->set.fdebug) {
bool inCallback = Curl_is_in_callback(data);
Curl_set_in_callback(data, true);
(void)(*data->set.fdebug)(data, type, ptr, size, data->set.debugdata);
Curl_set_in_callback(data, inCallback);
}
else {
switch(type) {
case CURLINFO_TEXT:
case CURLINFO_HEADER_OUT:
case CURLINFO_HEADER_IN:
fwrite(s_infotype[type], 2, 1, data->set.err);
fwrite(ptr, size, 1, data->set.err);
break;
default: /* nada */
break;
}
}
}
}
/* Curl_failf() is for messages stating why we failed.
* The message SHALL NOT include any LF or CR.
*/
void Curl_failf(struct Curl_easy *data, const char *fmt, ...)
{
DEBUGASSERT(!strchr(fmt, '\n'));
if(data->set.verbose || data->set.errorbuffer) {
va_list ap;
int len;
char error[CURL_ERROR_SIZE + 2];
va_start(ap, fmt);
len = mvsnprintf(error, CURL_ERROR_SIZE, fmt, ap);
if(data->set.errorbuffer && !data->state.errorbuf) {
strcpy(data->set.errorbuffer, error);
data->state.errorbuf = TRUE; /* wrote error string */
}
error[len++] = '\n';
error[len] = '\0';
Curl_debug(data, CURLINFO_TEXT, error, len);
va_end(ap);
}
}
#if !defined(CURL_DISABLE_VERBOSE_STRINGS)
/* Curl_infof() is for info message along the way */
#define MAXINFO 2048
static void trc_infof(struct Curl_easy *data, struct curl_trc_feat *feat,
const char * const fmt, va_list ap) CURL_PRINTF(3, 0);
static void trc_infof(struct Curl_easy *data, struct curl_trc_feat *feat,
const char * const fmt, va_list ap)
{
int len = 0;
char buffer[MAXINFO + 2];
if(feat)
len = msnprintf(buffer, MAXINFO, "[%s] ", feat->name);
len += mvsnprintf(buffer + len, MAXINFO - len, fmt, ap);
buffer[len++] = '\n';
buffer[len] = '\0';
Curl_debug(data, CURLINFO_TEXT, buffer, len);
}
void Curl_infof(struct Curl_easy *data, const char *fmt, ...)
{
DEBUGASSERT(!strchr(fmt, '\n'));
if(Curl_trc_is_verbose(data)) {
va_list ap;
va_start(ap, fmt);
trc_infof(data, data->state.feat, fmt, ap);
va_end(ap);
}
}
void Curl_trc_cf_infof(struct Curl_easy *data, struct Curl_cfilter *cf,
const char *fmt, ...)
{
DEBUGASSERT(cf);
if(Curl_trc_cf_is_verbose(cf, data)) {
va_list ap;
int len = 0;
char buffer[MAXINFO + 2];
if(data->state.feat)
len += msnprintf(buffer + len, MAXINFO - len, "[%s] ",
data->state.feat->name);
if(cf->sockindex)
len += msnprintf(buffer + len, MAXINFO - len, "[%s-%d] ",
cf->cft->name, cf->sockindex);
else
len += msnprintf(buffer + len, MAXINFO - len, "[%s] ", cf->cft->name);
va_start(ap, fmt);
len += mvsnprintf(buffer + len, MAXINFO - len, fmt, ap);
va_end(ap);
buffer[len++] = '\n';
buffer[len] = '\0';
Curl_debug(data, CURLINFO_TEXT, buffer, len);
}
}
struct curl_trc_feat Curl_trc_feat_read = {
"READ",
CURL_LOG_LVL_NONE,
};
struct curl_trc_feat Curl_trc_feat_write = {
"WRITE",
CURL_LOG_LVL_NONE,
};
void Curl_trc_read(struct Curl_easy *data, const char *fmt, ...)
{
DEBUGASSERT(!strchr(fmt, '\n'));
if(Curl_trc_ft_is_verbose(data, &Curl_trc_feat_read)) {
va_list ap;
va_start(ap, fmt);
trc_infof(data, &Curl_trc_feat_read, fmt, ap);
va_end(ap);
}
}
void Curl_trc_write(struct Curl_easy *data, const char *fmt, ...)
{
DEBUGASSERT(!strchr(fmt, '\n'));
if(Curl_trc_ft_is_verbose(data, &Curl_trc_feat_write)) {
va_list ap;
va_start(ap, fmt);
trc_infof(data, &Curl_trc_feat_write, fmt, ap);
va_end(ap);
}
}
#ifndef CURL_DISABLE_FTP
struct curl_trc_feat Curl_trc_feat_ftp = {
"FTP",
CURL_LOG_LVL_NONE,
};
void Curl_trc_ftp(struct Curl_easy *data, const char *fmt, ...)
{
DEBUGASSERT(!strchr(fmt, '\n'));
if(Curl_trc_ft_is_verbose(data, &Curl_trc_feat_ftp)) {
va_list ap;
va_start(ap, fmt);
trc_infof(data, &Curl_trc_feat_ftp, fmt, ap);
va_end(ap);
}
}
#endif /* !CURL_DISABLE_FTP */
static struct curl_trc_feat *trc_feats[] = {
&Curl_trc_feat_read,
&Curl_trc_feat_write,
#ifndef CURL_DISABLE_FTP
&Curl_trc_feat_ftp,
#endif
#ifndef CURL_DISABLE_DOH
&Curl_doh_trc,
#endif
NULL,
};
static struct Curl_cftype *cf_types[] = {
&Curl_cft_tcp,
&Curl_cft_udp,
&Curl_cft_unix,
&Curl_cft_tcp_accept,
&Curl_cft_happy_eyeballs,
&Curl_cft_setup,
#ifdef USE_NGHTTP2
&Curl_cft_nghttp2,
#endif
#ifdef USE_SSL
&Curl_cft_ssl,
#ifndef CURL_DISABLE_PROXY
&Curl_cft_ssl_proxy,
#endif
#endif
#if !defined(CURL_DISABLE_PROXY)
#if !defined(CURL_DISABLE_HTTP)
&Curl_cft_h1_proxy,
#ifdef USE_NGHTTP2
&Curl_cft_h2_proxy,
#endif
&Curl_cft_http_proxy,
#endif /* !CURL_DISABLE_HTTP */
&Curl_cft_haproxy,
&Curl_cft_socks_proxy,
#endif /* !CURL_DISABLE_PROXY */
#ifdef USE_HTTP3
&Curl_cft_http3,
connections: introduce http/3 happy eyeballs New cfilter HTTP-CONNECT for h3/h2/http1.1 eyeballing. - filter is installed when `--http3` in the tool is used (or the equivalent CURLOPT_ done in the library) - starts a QUIC/HTTP/3 connect right away. Should that not succeed after 100ms (subject to change), a parallel attempt is started for HTTP/2 and HTTP/1.1 via TCP - both attempts are subject to IPv6/IPv4 eyeballing, same as happens for other connections - tie timeout to the ip-version HAPPY_EYEBALLS_TIMEOUT - use a `soft` timeout at half the value. When the soft timeout expires, the HTTPS-CONNECT filter checks if the QUIC filter has received any data from the server. If not, it will start the HTTP/2 attempt. HTTP/3(ngtcp2) improvements. - setting call_data in all cfilter calls similar to http/2 and vtls filters for use in callback where no stream data is available. - returning CURLE_PARTIAL_FILE for prematurely terminated transfers - enabling pytest test_05 for h3 - shifting functionality to "connect" UDP sockets from ngtcp2 implementation into the udp socket cfilter. Because unconnected UDP sockets are weird. For example they error when adding to a pollset. HTTP/3(quiche) improvements. - fixed upload bug in quiche implementation, now passes 251 and pytest - error codes on stream RESET - improved debug logs - handling of DRAIN during connect - limiting pending event queue HTTP/2 cfilter improvements. - use LOG_CF macros for dynamic logging in debug build - fix CURLcode on RST streams to be CURLE_PARTIAL_FILE - enable pytest test_05 for h2 - fix upload pytests and improve parallel transfer performance. GOAWAY handling for ngtcp2/quiche - during connect, when the remote server refuses to accept new connections and closes immediately (so the local conn goes into DRAIN phase), the connection is torn down and a another attempt is made after a short grace period. This is the behaviour observed with nghttpx when we tell it to shut down gracefully. Tested in pytest test_03_02. TLS improvements - ALPN selection for SSL/SSL-PROXY filters in one vtls set of functions, replaces copy of logic in all tls backends. - standardized the infof logging of offered ALPNs - ALPN negotiated: have common function for all backends that sets alpn proprty and connection related things based on the negotiated protocol (or lack thereof). - new tests/tests-httpd/scorecard.py for testing h3/h2 protocol implementation. Invoke: python3 tests/tests-httpd/scorecard.py --help for usage. Improvements on gathering connect statistics and socket access. - new CF_CTRL_CONN_REPORT_STATS cfilter control for having cfilters report connection statistics. This is triggered when the connection has completely connected. - new void Curl_pgrsTimeWas(..) method to report a timer update with a timestamp of when it happend. This allows for updating timers "later", e.g. a connect statistic after full connectivity has been reached. - in case of HTTP eyeballing, the previous changes will update statistics only from the filter chain that "won" the eyeballing. - new cfilter query CF_QUERY_SOCKET for retrieving the socket used by a filter chain. Added methods Curl_conn_cf_get_socket() and Curl_conn_get_socket() for convenient use of this query. - Change VTLS backend to query their sub-filters for the socket when checks during the handshake are made. HTTP/3 documentation on how https eyeballing works. TLS improvements - ALPN selection for SSL/SSL-PROXY filters in one vtls set of functions, replaces copy of logic in all tls backends. - standardized the infof logging of offered ALPNs - ALPN negotiated: have common function for all backends that sets alpn proprty and connection related things based on the negotiated protocol (or lack thereof). Scorecard with Caddy. - configure can be run with `--with-test-caddy=path` to specify which caddy to use for testing - tests/tests-httpd/scorecard.py now measures download speeds with caddy pytest improvements - adding Makfile to clean gen dir - adding nghttpx rundir creation on start - checking httpd version 2.4.55 for test_05 cases where it is needed. Skipping with message if too old. - catch exception when checking for caddy existance on system. Closes #10349
2023-02-02 00:13:12 +08:00
#endif
#if !defined(CURL_DISABLE_HTTP) && !defined(USE_HYPER)
&Curl_cft_http_connect,
#endif
NULL,
};
CURLcode Curl_trc_opt(const char *config)
{
char *token, *tok_buf, *tmp;
size_t i;
int lvl;
tmp = strdup(config);
if(!tmp)
return CURLE_OUT_OF_MEMORY;
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;
}
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;
}
}
for(i = 0; trc_feats[i]; ++i) {
if(strcasecompare(token, "all")) {
trc_feats[i]->log_level = lvl;
}
else if(strcasecompare(token, trc_feats[i]->name)) {
trc_feats[i]->log_level = lvl;
break;
}
}
token = strtok_r(NULL, ", ", &tok_buf);
}
free(tmp);
return CURLE_OK;
}
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 /* DEBUGBUILD */
return CURLE_OK;
}
#else /* defined(CURL_DISABLE_VERBOSE_STRINGS) */
CURLcode Curl_trc_init(void)
{
return CURLE_OK;
}
#endif /* !defined(CURL_DISABLE_VERBOSE_STRINGS) */