QLOG: Minor updates
authorHugo Landau <hlandau@openssl.org>
Wed, 17 Jan 2024 10:01:46 +0000 (10:01 +0000)
committerHugo Landau <hlandau@openssl.org>
Fri, 2 Feb 2024 11:49:34 +0000 (11:49 +0000)
Reviewed-by: Matt Caswell <matt@openssl.org>
Reviewed-by: Neil Horman <nhorman@openssl.org>
(Merged from https://github.com/openssl/openssl/pull/22037)

doc/designs/quic-design/json-encoder.md
include/internal/qlog.h
ssl/quic/json_enc.c
ssl/quic/qlog.c
ssl/quic/qlog_event_helpers.c
ssl/quic/quic_channel.c

index fed938499a36630878d8e18790371a97d7135252..9ca568feabe639b685760bdfbbbd0afe229ae73d 100644 (file)
@@ -5,10 +5,11 @@ Approach
 --------
 
 The JSON encoder exists to support QLOG implementation. There is no intention to
-implement a decoder at this time. The encoder is intended to support
-zero-allocation automation using immediate calls without the use of an
-intermediate syntax tree representation. This enables highly efficient
-serialization when called from QUIC code without dynamic memory allocation.
+implement a decoder at this time. The encoder is intended to support automation
+using immediate calls without the use of an intermediate syntax tree
+representation and is expected to be zero-allocation in most cases. This enables
+highly efficient serialization when called from QUIC code without dynamic memory
+allocation.
 
 An example usage is as follows:
 
index e5e22904ed5544bfd0c78e3960713173222a6e41..e23a05b960807861bfe8605e7cfdacc0a2568413 100644 (file)
@@ -63,7 +63,6 @@ int ossl_qlog_event_try_begin(QLOG *qlog, uint32_t event_type,
                               const char *event_cat, const char *event_name,
                               const char *event_combined_name);
 void ossl_qlog_event_end(QLOG *qlog);
-void ossl_qlog_event_abort(QLOG *qlog);
 
 void ossl_qlog_group_begin(QLOG *qlog, const char *name);
 void ossl_qlog_group_end(QLOG *qlog);
index a95244f499080d664ecdbc39289a2e22a2e97d1e..f2c6f444e6703843383cfba0986c751f7570cc41 100644 (file)
@@ -292,11 +292,6 @@ int ossl_json_in_error(OSSL_JSON_ENC *json)
 static void json_write_qstring(OSSL_JSON_ENC *json, const char *str);
 static void json_indent(OSSL_JSON_ENC *json);
 
-static ossl_inline int json_in_error(const OSSL_JSON_ENC *json)
-{
-    return json->error;
-}
-
 static void json_raise_error(OSSL_JSON_ENC *json)
 {
     json->error = 1;
@@ -312,7 +307,7 @@ static void json_undefer(OSSL_JSON_ENC *json)
 
 static void json_write_char(OSSL_JSON_ENC *json, char ch)
 {
-    if (json_in_error(json))
+    if (ossl_json_in_error(json))
         return;
 
     json_undefer(json);
@@ -322,7 +317,7 @@ static void json_write_char(OSSL_JSON_ENC *json, char ch)
 
 static void json_write_str(OSSL_JSON_ENC *json, const char *s)
 {
-    if (json_in_error(json))
+    if (ossl_json_in_error(json))
         return;
 
     json_undefer(json);
@@ -350,7 +345,7 @@ static int json_pre_item(OSSL_JSON_ENC *json)
 {
     int s;
 
-    if (json_in_error(json))
+    if (ossl_json_in_error(json))
         return 0;
 
     switch (json->state) {
@@ -364,7 +359,7 @@ static int json_pre_item(OSSL_JSON_ENC *json)
 
         if (s == 1) {
             json_write_char(json, ',');
-            if (json_in_error(json))
+            if (ossl_json_in_error(json))
                 return 0;
 
             json_indent(json);
@@ -422,21 +417,25 @@ static void composite_end(OSSL_JSON_ENC *json, int type, char ch)
 {
     int was_defer = json->defer_indent;
 
-    if (json_in_error(json))
+    if (ossl_json_in_error(json))
         return;
 
     json->defer_indent = 0;
 
-    if (json_peek(json) != type)
+    if (json_peek(json) != type) {
+        json_raise_error(json);
         return;
+    }
 
     if (type == 0 && json->state == STATE_PRE_ITEM) {
         json_raise_error(json);
         return;
     }
 
-    if (!json_pop(json))
+    if (!json_pop(json)) {
+        json_raise_error(json);
         return;
+    }
 
     if (!was_defer)
         json_indent(json);
@@ -477,7 +476,7 @@ void ossl_json_array_end(OSSL_JSON_ENC *json)
  */
 void ossl_json_key(OSSL_JSON_ENC *json, const char *key)
 {
-    if (json_in_error(json))
+    if (ossl_json_in_error(json))
         return;
 
     if (json_peek(json) != 0) {
@@ -498,7 +497,7 @@ void ossl_json_key(OSSL_JSON_ENC *json, const char *key)
     }
 
     json_write_qstring(json, key);
-    if (json_in_error(json))
+    if (ossl_json_in_error(json))
         return;
 
     json_write_char(json, ':');
@@ -587,7 +586,7 @@ void ossl_json_i64(OSSL_JSON_ENC *json, int64_t value)
         : (uint64_t)-value;
     json_u64(json, uv, /*noquote=*/1);
 
-    if (quote && !json_in_error(json))
+    if (quote && !ossl_json_in_error(json))
         json_write_char(json, '"');
 }
 
@@ -626,7 +625,7 @@ json_write_qstring_inner(OSSL_JSON_ENC *json, const char *str, size_t str_len,
     int i;
     size_t j;
 
-    if (json_in_error(json))
+    if (ossl_json_in_error(json))
         return;
 
     json_write_char(json, '"');
@@ -651,7 +650,7 @@ json_write_qstring_inner(OSSL_JSON_ENC *json, const char *str, size_t str_len,
                 obuf[0] = '\\';
                 obuf[1] = 'u';
                 for (i = 0; i < 4; ++i)
-                    obuf[2 + i] = hex_digit((c >> ((3 - i) * 4)) & 0xF);
+                    obuf[2 + i] = hex_digit((c >> ((3 - i) * 4)) & 0x0F);
                 obuf[6] = '\0';
                 o = obuf;
             } else {
index 7815f2af39add4d505c2de73eb4c7cff83ecf6e3..8fa55c567ea1a3011ead7bee57c281df8094f222 100644 (file)
@@ -58,11 +58,10 @@ QLOG *ossl_qlog_new(const QLOG_TRACE_INFO *info)
     if (qlog == NULL)
         return NULL;
 
-    qlog->info = *info;
-
-    qlog->info.title        = NULL;
-    qlog->info.description  = NULL;
-    qlog->info.group_id     = NULL;
+    qlog->info.odcid        = info->odcid;
+    qlog->info.is_server    = info->is_server;
+    qlog->info.now_cb       = info->now_cb;
+    qlog->info.now_cb_arg   = info->now_cb_arg;
 
     if (info->title != NULL
         && (qlog->info.title = OPENSSL_strdup(info->title)) == NULL)
@@ -97,16 +96,19 @@ err:
 
 QLOG *ossl_qlog_new_from_env(const QLOG_TRACE_INFO *info)
 {
-    QLOG *qlog;
+    QLOG *qlog = NULL;
     const char *qlogdir = ossl_safe_getenv("QLOGDIR");
     const char *qfilter = ossl_safe_getenv("QFILTER");
     char qlogdir_sep, *filename = NULL;
     size_t i, l, strl;
 
-    if (info == NULL || qlogdir == NULL || strlen(qlogdir) == 0)
+    if (info == NULL || qlogdir == NULL)
         return NULL;
 
     l = strlen(qlogdir);
+    if (l == 0)
+        return NULL;
+
     qlogdir_sep = ossl_determine_dirsep(qlogdir);
 
     /* strlen("client" / "server"); strlen(".sqlog"); _; separator; _; NUL */
@@ -122,29 +124,26 @@ QLOG *ossl_qlog_new_from_env(const QLOG_TRACE_INFO *info)
     for (i = 0; i < info->odcid.id_len; ++i)
         l += sprintf(filename + l, "%02x", info->odcid.id[i]);
 
-    l += snprintf(filename + l, strl, "_%s.sqlog",
+    l += snprintf(filename + l, strl - l, "_%s.sqlog",
                   info->is_server ? "server" : "client");
 
     qlog = ossl_qlog_new(info);
-    if (qlog == NULL) {
-        OPENSSL_free(filename);
-        return NULL;
-    }
+    if (qlog == NULL)
+        goto err;
 
-    if (!ossl_qlog_set_sink_filename(qlog, filename)) {
-        OPENSSL_free(filename);
-        ossl_qlog_free(qlog);
-        return NULL;
-    }
+    if (!ossl_qlog_set_sink_filename(qlog, filename))
+        goto err;
 
-    if (qfilter != NULL && !ossl_qlog_set_filter(qlog, qfilter)) {
-        OPENSSL_free(filename);
-        ossl_qlog_free(qlog);
-        return NULL;
-    }
+    if (qfilter != NULL && !ossl_qlog_set_filter(qlog, qfilter))
+        goto err;
 
     OPENSSL_free(filename);
     return qlog;
+
+err:
+    OPENSSL_free(filename);
+    ossl_qlog_free(qlog);
+    return NULL;
 }
 
 void ossl_qlog_free(QLOG *qlog)
@@ -293,7 +292,7 @@ static void qlog_event_seq_header(QLOG *qlog)
                 ossl_json_array_begin(&qlog->json);
                 {
                     ossl_json_str(&qlog->json, "QUIC");
-                }
+                } /* protocol_type */
                 ossl_json_array_end(&qlog->json);
 
                 write_str_once(qlog, "group_id", (char **)&qlog->info.group_id);
@@ -303,9 +302,9 @@ static void qlog_event_seq_header(QLOG *qlog)
                 {
                     ossl_json_key(&qlog->json, "process_id");
                     ossl_json_u64(&qlog->json, (uint64_t)getpid());
-                }
+                } /* system_info */
                 ossl_json_object_end(&qlog->json);
-            }
+            } /* common_fields */
             ossl_json_object_end(&qlog->json);
 
             ossl_json_key(&qlog->json, "vantage_point");
@@ -314,9 +313,9 @@ static void qlog_event_seq_header(QLOG *qlog)
                 ossl_json_key(&qlog->json, "type");
                 ossl_json_str(&qlog->json, qlog->info.is_server
                                     ? "server" : "client");
-            }
+            } /* vantage_point */
             ossl_json_object_end(&qlog->json);
-        }
+        } /* trace */
         ossl_json_object_end(&qlog->json);
     }
     ossl_json_object_end(&qlog->json);
@@ -380,7 +379,7 @@ int ossl_qlog_event_try_begin(QLOG *qlog,
     return 1;
 }
 
-static void qlog_event_end(QLOG *qlog, int abort)
+void ossl_qlog_event_end(QLOG *qlog)
 {
     if (!ossl_assert(qlog != NULL && qlog->event_type != QLOG_EVENT_TYPE_NONE))
         return;
@@ -389,16 +388,6 @@ static void qlog_event_end(QLOG *qlog, int abort)
     qlog->event_type = QLOG_EVENT_TYPE_NONE;
 }
 
-void ossl_qlog_event_end(QLOG *qlog)
-{
-    qlog_event_end(qlog, /*abort=*/0);
-}
-
-void ossl_qlog_event_abort(QLOG *qlog)
-{
-    qlog_event_end(qlog, /*abort=*/1);
-}
-
 /*
  * Field Generators
  * ================
@@ -625,6 +614,9 @@ static void filter_apply(size_t *enabled, int add,
 
 static int lex_fail(struct lexer *lex, const char *msg)
 {
+    /*
+     * TODO(QLOG): Determine how to print log messages about bad filter strings
+     */
     lex->p = lex->term_end = lex->end;
     return 0;
 }
index 16fd8ae74ef1e4e1722fa532245f09b6742f6996..fd1d64af211202425d7da53a4a10a054545faf2b 100644 (file)
@@ -203,8 +203,8 @@ static void ignore_res(int x) {}
  * goes wrong before then) while avoiding the need to keep around bookkeeping
  * data on what frames it contained.
  */
-static int log_frame(QLOG *qlog_instance, PACKET *pkt,
-                     uint64_t *need_skip)
+static int log_frame_actual(QLOG *qlog_instance, PACKET *pkt,
+                            uint64_t *need_skip)
 {
     uint64_t frame_type;
     OSSL_QUIC_FRAME_ACK ack;
@@ -232,7 +232,6 @@ static int log_frame(QLOG *qlog_instance, PACKET *pkt,
             goto unknown;
 
         QLOG_STR("frame_type", "ping");
-        QLOG_U64("length", 1);
         break;
     case OSSL_QUIC_FRAME_TYPE_ACK_WITHOUT_ECN:
     case OSSL_QUIC_FRAME_TYPE_ACK_WITH_ECN:
@@ -451,7 +450,8 @@ static int log_frame(QLOG *qlog_instance, PACKET *pkt,
             uint64_t stream_id, x;
 
             if (!ossl_quic_wire_decode_frame_stream_data_blocked(pkt,
-                                                                 &stream_id, &x))
+                                                                 &stream_id,
+                                                                 &x))
                 goto unknown;
 
             QLOG_STR("frame_type", "stream_data_blocked");
@@ -511,13 +511,26 @@ unknown:
     return 1;
 }
 
+static void log_frame(QLOG *qlog_instance, PACKET *pkt,
+                      uint64_t *need_skip)
+{
+    size_t rem_before, rem_after;
+
+    rem_before = PACKET_remaining(pkt);
+
+    if (!log_frame_actual(qlog_instance, pkt, need_skip))
+        return;
+
+    rem_after = PACKET_remaining(pkt);
+    QLOG_U64("length", rem_before - rem_after);
+}
+
 static int log_frames(QLOG *qlog_instance,
                       const OSSL_QTX_IOVEC *iovec,
                       size_t num_iovec)
 {
     size_t i;
     PACKET pkt;
-    size_t rem_before, rem_after;
     uint64_t need_skip = 0;
 
     for (i = 0; i < num_iovec; ++i) {
@@ -538,17 +551,10 @@ static int log_frames(QLOG *qlog_instance,
                 continue;
             }
 
-            rem_before = PACKET_remaining(&pkt);
-
             QLOG_BEGIN(NULL)
             {
-                if (!log_frame(qlog_instance, &pkt, &need_skip))
-                    goto cont;
-
-                rem_after = PACKET_remaining(&pkt);
-                QLOG_U64("length", rem_before - rem_after);
+                log_frame(qlog_instance, &pkt, &need_skip);
             }
-cont:
             QLOG_END()
         }
     }
index ea6a76818566485c59ddf4b83461742c9fa7de7e..ff394bbe72234e5b2c2b4d1d146ba33ed714e26c 100644 (file)
@@ -1504,43 +1504,41 @@ static int ch_on_transport_params(const unsigned char *params,
             break;
 
         case QUIC_TPARAM_PREFERRED_ADDR:
-            {
-                /* TODO(QUIC FUTURE): Handle preferred address. */
-                if (got_preferred_addr) {
-                    reason = TP_REASON_DUP("PREFERRED_ADDR");
-                    goto malformed;
-                }
+            /* TODO(QUIC FUTURE): Handle preferred address. */
+            if (got_preferred_addr) {
+                reason = TP_REASON_DUP("PREFERRED_ADDR");
+                goto malformed;
+            }
 
-                /*
-                 * RFC 9000 s. 18.2: "A server that chooses a zero-length
-                 * connection ID MUST NOT provide a preferred address.
-                 * Similarly, a server MUST NOT include a zero-length connection
-                 * ID in this transport parameter. A client MUST treat a
-                 * violation of these requirements as a connection error of type
-                 * TRANSPORT_PARAMETER_ERROR."
-                 */
-                if (ch->is_server) {
-                    reason = TP_REASON_SERVER_ONLY("PREFERRED_ADDR");
-                    goto malformed;
-                }
-
-                if (ch->cur_remote_dcid.id_len == 0) {
-                    reason = "PREFERRED_ADDR provided for zero-length CID";
-                    goto malformed;
-                }
-
-                if (!ossl_quic_wire_decode_transport_param_preferred_addr(&pkt, &pfa)) {
-                    reason = TP_REASON_MALFORMED("PREFERRED_ADDR");
-                    goto malformed;
-                }
-
-                if (pfa.cid.id_len == 0) {
-                    reason = "zero-length CID in PREFERRED_ADDR";
-                    goto malformed;
-                }
-
-                got_preferred_addr = 1;
+            /*
+             * RFC 9000 s. 18.2: "A server that chooses a zero-length
+             * connection ID MUST NOT provide a preferred address.
+             * Similarly, a server MUST NOT include a zero-length connection
+             * ID in this transport parameter. A client MUST treat a
+             * violation of these requirements as a connection error of type
+             * TRANSPORT_PARAMETER_ERROR."
+             */
+            if (ch->is_server) {
+                reason = TP_REASON_SERVER_ONLY("PREFERRED_ADDR");
+                goto malformed;
+            }
+
+            if (ch->cur_remote_dcid.id_len == 0) {
+                reason = "PREFERRED_ADDR provided for zero-length CID";
+                goto malformed;
+            }
+
+            if (!ossl_quic_wire_decode_transport_param_preferred_addr(&pkt, &pfa)) {
+                reason = TP_REASON_MALFORMED("PREFERRED_ADDR");
+                goto malformed;
             }
+
+            if (pfa.cid.id_len == 0) {
+                reason = "zero-length CID in PREFERRED_ADDR";
+                goto malformed;
+            }
+
+            got_preferred_addr = 1;
             break;
 
         case QUIC_TPARAM_DISABLE_ACTIVE_MIGRATION: