curl/lib/curl_log.c
Stefan Eissing 671158242d
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 09:57:34 +01:00

224 lines
5.6 KiB
C

/***************************************************************************
* _ _ ____ _
* 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_log.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 "http2.h"
#include "http_proxy.h"
#include "cf-http.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);
}
}
/* Curl_infof() is for info message along the way */
#define MAXINFO 2048
void Curl_infof(struct Curl_easy *data, const char *fmt, ...)
{
DEBUGASSERT(!strchr(fmt, '\n'));
if(data && data->set.verbose) {
va_list ap;
int len;
char buffer[MAXINFO + 2];
va_start(ap, fmt);
len = mvsnprintf(buffer, MAXINFO, fmt, ap);
va_end(ap);
buffer[len++] = '\n';
buffer[len] = '\0';
Curl_debug(data, CURLINFO_TEXT, buffer, len);
}
}
#ifdef DEBUGBUILD
void Curl_log_cf_debug(struct Curl_easy *data, struct Curl_cfilter *cf,
const char *fmt, ...)
{
DEBUGASSERT(cf);
if(data && Curl_log_cf_is_debug(cf)) {
va_list ap;
int len;
char buffer[MAXINFO + 2];
len = msnprintf(buffer, MAXINFO, "[CONN-%ld%s-%s] ",
cf->conn->connection_id, cf->sockindex? "/2" : "",
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);
}
}
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,
&Curl_cft_ssl_proxy,
#endif
#if !defined(CURL_DISABLE_PROXY)
#if !defined(CURL_DISABLE_HTTP)
&Curl_cft_http_proxy,
#endif /* !CURL_DISABLE_HTTP */
&Curl_cft_haproxy,
&Curl_cft_socks_proxy,
#endif /* !CURL_DISABLE_PROXY */
#ifdef ENABLE_QUIC
&Curl_cft_http3,
#endif
#if !defined(CURL_DISABLE_HTTP) && !defined(USE_HYPER)
&Curl_cft_http_connect,
#endif
NULL,
};
#ifndef ARRAYSIZE
#define ARRAYSIZE(A) (sizeof(A)/sizeof((A)[0]))
#endif
CURLcode Curl_log_init(void)
{
const char *setting = getenv("CURL_DEBUG");
if(setting) {
char *token, *tok_buf, *tmp;
size_t i;
tmp = strdup(setting);
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);
}
free(tmp);
}
return CURLE_OK;
}
#else /* DEBUGBUILD */
CURLcode Curl_log_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,
const char *fmt, ...)
{
(void)data;
(void)cf;
(void)fmt;
}
#endif
#endif /* !DEBUGBUILD */