]> git.ipfire.org Git - thirdparty/curl.git/commitdiff
http3: quiche, handshake optimization, trace cleanup
authorStefan Eissing <stefan@eissing.org>
Mon, 7 Aug 2023 11:50:14 +0000 (13:50 +0200)
committerDaniel Stenberg <daniel@haxx.se>
Tue, 8 Aug 2023 14:33:53 +0000 (16:33 +0200)
- load x509 store after clienthello
- cleanup of tracing

Closes #11618

lib/vquic/curl_quiche.c

index c3c20eece2a91f94d55490ab9b2a5f3960678d5d..9776de8992d98d8c20eca3ec44c848e212dd0353 100644 (file)
@@ -88,54 +88,6 @@ static void keylog_callback(const SSL *ssl, const char *line)
   Curl_tls_keylog_write_line(line);
 }
 
-static SSL_CTX *quic_ssl_ctx(struct Curl_easy *data)
-{
-  SSL_CTX *ssl_ctx = SSL_CTX_new(TLS_method());
-
-  SSL_CTX_set_alpn_protos(ssl_ctx,
-                          (const uint8_t *)QUICHE_H3_APPLICATION_PROTOCOL,
-                          sizeof(QUICHE_H3_APPLICATION_PROTOCOL) - 1);
-
-  SSL_CTX_set_default_verify_paths(ssl_ctx);
-
-  /* Open the file if a TLS or QUIC backend has not done this before. */
-  Curl_tls_keylog_open();
-  if(Curl_tls_keylog_enabled()) {
-    SSL_CTX_set_keylog_callback(ssl_ctx, keylog_callback);
-  }
-
-  {
-    struct connectdata *conn = data->conn;
-    if(conn->ssl_config.verifypeer) {
-      const char * const ssl_cafile = conn->ssl_config.CAfile;
-      const char * const ssl_capath = conn->ssl_config.CApath;
-      if(ssl_cafile || ssl_capath) {
-        SSL_CTX_set_verify(ssl_ctx, SSL_VERIFY_PEER, NULL);
-        /* tell OpenSSL where to find CA certificates that are used to verify
-           the server's certificate. */
-        if(!SSL_CTX_load_verify_locations(ssl_ctx, ssl_cafile, ssl_capath)) {
-          /* Fail if we insist on successfully verifying the server. */
-          failf(data, "error setting certificate verify locations:"
-                "  CAfile: %s CApath: %s",
-                ssl_cafile ? ssl_cafile : "none",
-                ssl_capath ? ssl_capath : "none");
-          return NULL;
-        }
-        infof(data, " CAfile: %s", ssl_cafile ? ssl_cafile : "none");
-        infof(data, " CApath: %s", ssl_capath ? ssl_capath : "none");
-      }
-#ifdef CURL_CA_FALLBACK
-      else {
-        /* verifying the peer without any CA certificates won't work so
-           use openssl's built-in default as fallback */
-        SSL_CTX_set_default_verify_paths(ssl_ctx);
-      }
-#endif
-    }
-  }
-  return ssl_ctx;
-}
-
 struct cf_quiche_ctx {
   struct cf_quic_ctx q;
   quiche_conn *qconn;
@@ -154,6 +106,7 @@ struct cf_quiche_ctx {
   size_t sends_on_hold;              /* # of streams with SEND_HOLD set */
   BIT(goaway);                       /* got GOAWAY from server */
   BIT(got_first_byte);               /* if first byte was received */
+  BIT(x509_store_setup);             /* if x509 store has been set up */
 };
 
 #ifdef DEBUG_QUICHE
@@ -181,6 +134,76 @@ static void cf_quiche_ctx_clear(struct cf_quiche_ctx *ctx)
   }
 }
 
+static CURLcode quic_x509_store_setup(struct Curl_cfilter *cf,
+                                      struct Curl_easy *data)
+{
+  struct cf_quiche_ctx *ctx = cf->ctx;
+
+  if(!ctx->x509_store_setup) {
+    if(cf->conn->ssl_config.verifypeer) {
+      const char * const ssl_cafile = cf->conn->ssl_config.CAfile;
+      const char * const ssl_capath = cf->conn->ssl_config.CApath;
+      if(ssl_cafile || ssl_capath) {
+        SSL_CTX_set_verify(ctx->sslctx, SSL_VERIFY_PEER, NULL);
+        /* tell OpenSSL where to find CA certificates that are used to verify
+           the server's certificate. */
+        if(!SSL_CTX_load_verify_locations(
+              ctx->sslctx, ssl_cafile, ssl_capath)) {
+          /* Fail if we insist on successfully verifying the server. */
+          failf(data, "error setting certificate verify locations:"
+                "  CAfile: %s CApath: %s",
+                ssl_cafile ? ssl_cafile : "none",
+                ssl_capath ? ssl_capath : "none");
+          return CURLE_SSL_CACERT_BADFILE;
+        }
+        infof(data, " CAfile: %s", ssl_cafile ? ssl_cafile : "none");
+        infof(data, " CApath: %s", ssl_capath ? ssl_capath : "none");
+      }
+#ifdef CURL_CA_FALLBACK
+      else {
+        /* verifying the peer without any CA certificates won't work so
+           use openssl's built-in default as fallback */
+        SSL_CTX_set_default_verify_paths(ssl_ctx);
+      }
+#endif
+    }
+    ctx->x509_store_setup = TRUE;
+  }
+  return CURLE_OK;
+}
+
+static CURLcode quic_ssl_setup(struct Curl_cfilter *cf, struct Curl_easy *data)
+{
+  struct cf_quiche_ctx *ctx = cf->ctx;
+
+  (void)data;
+  DEBUGASSERT(!ctx->sslctx);
+  ctx->sslctx = SSL_CTX_new(TLS_method());
+  if(!ctx->sslctx)
+    return CURLE_OUT_OF_MEMORY;
+
+  SSL_CTX_set_alpn_protos(ctx->sslctx,
+                          (const uint8_t *)QUICHE_H3_APPLICATION_PROTOCOL,
+                          sizeof(QUICHE_H3_APPLICATION_PROTOCOL) - 1);
+
+  SSL_CTX_set_default_verify_paths(ctx->sslctx);
+
+  /* Open the file if a TLS or QUIC backend has not done this before. */
+  Curl_tls_keylog_open();
+  if(Curl_tls_keylog_enabled()) {
+    SSL_CTX_set_keylog_callback(ctx->sslctx, keylog_callback);
+  }
+
+  ctx->ssl = SSL_new(ctx->sslctx);
+  if(!ctx->ssl)
+    return CURLE_QUIC_CONNECT_ERROR;
+
+  SSL_set_app_data(ctx->ssl, cf);
+  SSL_set_tlsext_host_name(ctx->ssl, cf->conn->host.name);
+
+  return CURLE_OK;
+}
+
 /**
  * All about the H3 internals of a stream
  */
@@ -217,7 +240,7 @@ 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)
-      CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] suspend sending",
+      CURL_TRC_CF(data, cf, "[%"PRId64"] suspend sending",
                   H3_STREAM_ID(data));
     else
       CURL_TRC_CF(data, cf, "[%s] suspend sending", data->state.url);
@@ -233,7 +256,7 @@ 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)
-      CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] resume sending",
+      CURL_TRC_CF(data, cf, "[%"PRId64"] resume sending",
                   H3_STREAM_ID(data));
     else
       CURL_TRC_CF(data, cf, "[%s] resume sending", data->state.url);
@@ -275,7 +298,6 @@ 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);
-  CURL_TRC_CF(data, cf, "data setup");
   return CURLE_OK;
 }
 
@@ -286,7 +308,7 @@ static void h3_data_done(struct Curl_cfilter *cf, struct Curl_easy *data)
 
   (void)cf;
   if(stream) {
-    CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] easy handle is done", stream->id);
+    CURL_TRC_CF(data, cf, "[%"PRId64"] easy handle is done", stream->id);
     if(stream_send_is_suspended(data)) {
       data->req.keepon &= ~KEEP_SEND_HOLD;
       --ctx->sends_on_hold;
@@ -376,8 +398,12 @@ static int cb_each_header(uint8_t *name, size_t name_len,
   struct stream_ctx *stream = H3_STREAM_CTX(x->data);
   CURLcode result;
 
-  (void)stream;
+  if(!stream)
+    return CURLE_OK;
+
   if((name_len == 7) && !strncmp(HTTP_PSEUDO_STATUS, (char *)name, 7)) {
+    CURL_TRC_CF(x->data, x->cf, "[%" PRId64 "] status: %.*s",
+                stream->id, (int)value_len, value);
     result = write_resp_raw(x->cf, x->data, "HTTP/3 ", sizeof("HTTP/3 ") - 1);
     if(!result)
       result = write_resp_raw(x->cf, x->data, value, value_len);
@@ -385,6 +411,9 @@ static int cb_each_header(uint8_t *name, size_t name_len,
       result = write_resp_raw(x->cf, x->data, " \r\n", 3);
   }
   else {
+    CURL_TRC_CF(x->data, x->cf, "[%" PRId64 "] header: %.*s: %.*s",
+                stream->id, (int)name_len, name,
+                (int)value_len, value);
     result = write_resp_raw(x->cf, x->data, name, name_len);
     if(!result)
       result = write_resp_raw(x->cf, x->data, ": ", 2);
@@ -394,10 +423,8 @@ 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) {
-    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);
+    CURL_TRC_CF(x->data, x->cf, "[%"PRId64"] on header error %d",
+                stream->id, result);
   }
   return result;
 }
@@ -452,7 +479,7 @@ static CURLcode cf_recv_body(struct Curl_cfilter *cf,
                              stream_resp_read, &cb_ctx, &result);
 
   if(nwritten < 0 && result != CURLE_AGAIN) {
-    CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] recv_body error %zd",
+    CURL_TRC_CF(data, cf, "[%"PRId64"] recv_body error %zd",
                 stream->id, nwritten);
     failf(data, "Error %d in HTTP/3 response body for stream[%"PRId64"]",
           result, stream->id);
@@ -511,7 +538,7 @@ static CURLcode h3_process_event(struct Curl_cfilter *cf,
             rc, stream3_id);
       return CURLE_RECV_ERROR;
     }
-    CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"][HEADERS]", stream3_id);
+    CURL_TRC_CF(data, cf, "[%"PRId64"] <- [HEADERS]", stream3_id);
     break;
 
   case QUICHE_H3_EVENT_DATA:
@@ -521,7 +548,7 @@ static CURLcode h3_process_event(struct Curl_cfilter *cf,
     break;
 
   case QUICHE_H3_EVENT_RESET:
-    CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"][RESET]", stream3_id);
+    CURL_TRC_CF(data, cf, "[%"PRId64"] RESET", stream3_id);
     stream->closed = TRUE;
     stream->reset = TRUE;
     stream->send_closed = TRUE;
@@ -529,7 +556,7 @@ static CURLcode h3_process_event(struct Curl_cfilter *cf,
     break;
 
   case QUICHE_H3_EVENT_FINISHED:
-    CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"][FINISHED]", stream3_id);
+    CURL_TRC_CF(data, cf, "[%"PRId64"] CLOSED", stream3_id);
     if(!stream->resp_hds_complete) {
       result = write_resp_raw(cf, data, "\r\n", 2);
       if(result)
@@ -541,11 +568,11 @@ static CURLcode h3_process_event(struct Curl_cfilter *cf,
     break;
 
   case QUICHE_H3_EVENT_GOAWAY:
-    CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"][GOAWAY]", stream3_id);
+    CURL_TRC_CF(data, cf, "[%"PRId64"] <- [GOAWAY]", stream3_id);
     break;
 
   default:
-    CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] recv, unhandled event %d",
+    CURL_TRC_CF(data, cf, "[%"PRId64"] recv, unhandled event %d",
                 stream3_id, quiche_h3_event_type(ev));
     break;
   }
@@ -568,23 +595,23 @@ static CURLcode cf_poll_events(struct Curl_cfilter *cf,
       break;
     }
     else if(stream3_id < 0) {
-      CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] error poll: %"PRId64,
+      CURL_TRC_CF(data, cf, "[%"PRId64"] error poll: %"PRId64,
                   stream? stream->id : -1, stream3_id);
       return CURLE_HTTP3;
     }
 
     sdata = get_stream_easy(cf, data, stream3_id);
     if(!sdata) {
-      CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] discard event %s for "
-                  "unknown [h3sid=%"PRId64"]",
+      CURL_TRC_CF(data, cf, "[%"PRId64"] discard event %s for "
+                  "unknown [%"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) {
-        CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] error processing event %s "
-                    "for [h3sid=%"PRId64"] -> %d",
+        CURL_TRC_CF(data, cf, "[%"PRId64"] error processing event %s "
+                    "for [%"PRId64"] -> %d",
                     stream? stream->id : -1, cf_ev_name(ev),
                     stream3_id, result);
         if(data == sdata) {
@@ -661,6 +688,10 @@ static CURLcode cf_process_ingress(struct Curl_cfilter *cf,
   CURLcode result;
 
   DEBUGASSERT(ctx->qconn);
+  result = quic_x509_store_setup(cf, data);
+  if(result)
+    return result;
+
   rctx.cf = cf;
   rctx.data = data;
   rctx.pkts = 0;
@@ -788,7 +819,7 @@ 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;
-    CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, was reset -> %d",
+    CURL_TRC_CF(data, cf, "[%" PRId64 "] cf_recv, was reset -> %d",
                 stream->id, *err);
   }
   else if(!stream->resp_got_header) {
@@ -798,14 +829,12 @@ static ssize_t recv_closed_stream(struct Curl_cfilter *cf,
           stream->id);
     /* *err = CURLE_PARTIAL_FILE; */
     *err = CURLE_RECV_ERROR;
-    CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed incomplete"
+    CURL_TRC_CF(data, cf, "[%" PRId64 "] cf_recv, closed incomplete"
                 " -> %d", stream->id, *err);
   }
   else {
     *err = CURLE_OK;
     nread = 0;
-    CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_recv, closed ok"
-                " -> %d", stream->id, *err);
   }
   return nread;
 }
@@ -826,7 +855,7 @@ 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);
-    CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] read recvbuf(len=%zu) "
+    CURL_TRC_CF(data, cf, "[%" PRId64 "] read recvbuf(len=%zu) "
                 "-> %zd, %d", stream->id, len, nread, *err);
     if(nread < 0)
       goto out;
@@ -843,7 +872,7 @@ 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);
-    CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] read recvbuf(len=%zu) "
+    CURL_TRC_CF(data, cf, "[%" PRId64 "] read recvbuf(len=%zu) "
                 "-> %zd, %d", stream->id, len, nread, *err);
     if(nread < 0)
       goto out;
@@ -877,7 +906,7 @@ out:
   }
   if(nread > 0)
     ctx->data_recvd += nread;
-  CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] cf_recv(total=%"
+  CURL_TRC_CF(data, cf, "[%"PRId64"] cf_recv(total=%"
               CURL_FORMAT_CURL_OFF_T ") -> %zd, %d",
               stream ? stream->id : (int64_t)0,
               ctx->data_recvd, nread, *err);
@@ -990,9 +1019,15 @@ static ssize_t h3_open_stream(struct Curl_cfilter *cf,
   stream->closed = FALSE;
   stream->reset = FALSE;
 
-  infof(data, "Using HTTP/3 Stream ID: %" PRId64, stream3_id);
-  CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] opened for %s",
-              stream3_id, data->state.url);
+  if(Curl_trc_is_verbose(data)) {
+    infof(data, "[HTTP/3] [%" PRId64 "] OPENED stream for %s",
+          stream->id, data->state.url);
+    for(i = 0; i < nheader; ++i) {
+      infof(data, "[HTTP/3] [%" PRId64 "] [%.*s: %.*s]", stream->id,
+            (int)nva[i].name_len, nva[i].name,
+            (int)nva[i].value_len, nva[i].value);
+    }
+  }
 
 out:
   free(nva);
@@ -1030,7 +1065,7 @@ 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)) {
-        CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] send_body(len=%zu) "
+        CURL_TRC_CF(data, cf, "[%" PRId64 "] send_body(len=%zu) "
                     "-> window exhausted", stream->id, len);
         stream_send_suspend(cf, data);
       }
@@ -1039,14 +1074,14 @@ 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) {
-      CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] send_body(len=%zu) "
+      CURL_TRC_CF(data, cf, "[%" PRId64 "] send_body(len=%zu) "
                   "-> exceeds size", stream->id, len);
       *err = CURLE_SEND_ERROR;
       nwritten = -1;
       goto out;
     }
     else if(nwritten < 0) {
-      CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] send_body(len=%zu) "
+      CURL_TRC_CF(data, cf, "[%" PRId64 "] send_body(len=%zu) "
                   "-> quiche err %zd", stream->id, len, nwritten);
       *err = CURLE_SEND_ERROR;
       nwritten = -1;
@@ -1061,7 +1096,7 @@ static ssize_t cf_quiche_send(struct Curl_cfilter *cf, struct Curl_easy *data,
       if(stream->upload_left == 0)
         stream->send_closed = TRUE;
 
-      CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] send body(len=%zu, "
+      CURL_TRC_CF(data, cf, "[%" PRId64 "] send body(len=%zu, "
                   "left=%" CURL_FORMAT_CURL_OFF_T ") -> %zd",
                   stream->id, len, stream->upload_left, nwritten);
       *err = CURLE_OK;
@@ -1074,7 +1109,7 @@ out:
     *err = result;
     nwritten = -1;
   }
-  CURL_TRC_CF(data, cf, "[h3sid=%" PRId64 "] cf_send(len=%zu) -> %zd, %d",
+  CURL_TRC_CF(data, cf, "[%" PRId64 "] cf_send(len=%zu) -> %zd, %d",
               stream? stream->id : -1, len, nwritten, *err);
   return nwritten;
 }
@@ -1164,7 +1199,7 @@ 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);
-      CURL_TRC_CF(data, cf, "[h3sid=%"PRId64"] DONE_SEND -> %zd, %d",
+      CURL_TRC_CF(data, cf, "[%"PRId64"] DONE_SEND -> %zd, %d",
                   stream->id, sent, result);
     }
     break;
@@ -1291,15 +1326,9 @@ static CURLcode cf_connect_start(struct Curl_cfilter *cf,
 
   DEBUGASSERT(!ctx->ssl);
   DEBUGASSERT(!ctx->sslctx);
-  ctx->sslctx = quic_ssl_ctx(data);
-  if(!ctx->sslctx)
-    return CURLE_QUIC_CONNECT_ERROR;
-  ctx->ssl = SSL_new(ctx->sslctx);
-  if(!ctx->ssl)
-    return CURLE_QUIC_CONNECT_ERROR;
-
-  SSL_set_app_data(ctx->ssl, cf);
-  SSL_set_tlsext_host_name(ctx->ssl, cf->conn->host.name);
+  result = quic_ssl_setup(cf, data);
+  if(result)
+    return result;
 
   result = Curl_rand(data, ctx->scid, sizeof(ctx->scid));
   if(result)