/src/openssl33/ssl/quic/qlog_event_helpers.c

Source
/*
 * Copyright 2023-2025 The OpenSSL Project Authors. All Rights Reserved.
 *
 * Licensed under the Apache License 2.0 (the "License").  You may not use
 * this file except in compliance with the License.  You can obtain a copy
 * in the file LICENSE in the source distribution or at
 * https://www.openssl.org/source/license.html
 */

#include "internal/qlog_event_helpers.h"
#include "internal/common.h"
#include "internal/packet.h"
#include "internal/quic_channel.h"
#include "internal/quic_error.h"

void ossl_qlog_event_connectivity_connection_started(QLOG *qlog,
    const QUIC_CONN_ID *init_dcid)
{
#ifndef OPENSSL_NO_QLOG
    QLOG_EVENT_BEGIN(qlog, connectivity, connection_started)
    QLOG_STR("protocol", "quic");
    QLOG_CID("dst_cid", init_dcid);
    QLOG_EVENT_END()
#endif
}

#ifndef OPENSSL_NO_QLOG
static const char *map_state_to_qlog(uint32_t state,
    int handshake_complete,
    int handshake_confirmed)
{
    switch (state) {
    default:
    case QUIC_CHANNEL_STATE_IDLE:
        return NULL;

    case QUIC_CHANNEL_STATE_ACTIVE:
        if (handshake_confirmed)
            return "handshake_confirmed";
        else if (handshake_complete)
            return "handshake_complete";
        else
            return "attempted";

    case QUIC_CHANNEL_STATE_TERMINATING_CLOSING:
        return "closing";

    case QUIC_CHANNEL_STATE_TERMINATING_DRAINING:
        return "draining";

    case QUIC_CHANNEL_STATE_TERMINATED:
        return "closed";
    }
}
#endif

void ossl_qlog_event_connectivity_connection_state_updated(QLOG *qlog,
    uint32_t old_state,
    uint32_t new_state,
    int handshake_complete,
    int handshake_confirmed)
{
#ifndef OPENSSL_NO_QLOG
    const char *state_s;

    QLOG_EVENT_BEGIN(qlog, connectivity, connection_state_updated)
    state_s = map_state_to_qlog(new_state,
        handshake_complete,
        handshake_confirmed);

    if (state_s != NULL)
        QLOG_STR("state", state_s);
    QLOG_EVENT_END()
#endif
}

#ifndef OPENSSL_NO_QLOG
static const char *quic_err_to_qlog(uint64_t error_code)
{
    switch (error_code) {
    case OSSL_QUIC_ERR_INTERNAL_ERROR:
        return "internal_error";
    case OSSL_QUIC_ERR_CONNECTION_REFUSED:
        return "connection_refused";
    case OSSL_QUIC_ERR_FLOW_CONTROL_ERROR:
        return "flow_control_error";
    case OSSL_QUIC_ERR_STREAM_LIMIT_ERROR:
        return "stream_limit_error";
    case OSSL_QUIC_ERR_STREAM_STATE_ERROR:
        return "stream_state_error";
    case OSSL_QUIC_ERR_FINAL_SIZE_ERROR:
        return "final_size_error";
    case OSSL_QUIC_ERR_FRAME_ENCODING_ERROR:
        return "frame_encoding_error";
    case OSSL_QUIC_ERR_TRANSPORT_PARAMETER_ERROR:
        return "transport_parameter_error";
    case OSSL_QUIC_ERR_CONNECTION_ID_LIMIT_ERROR:
        return "connection_id_limit_error";
    case OSSL_QUIC_ERR_PROTOCOL_VIOLATION:
        return "protocol_violation";
    case OSSL_QUIC_ERR_INVALID_TOKEN:
        return "invalid_token";
    case OSSL_QUIC_ERR_APPLICATION_ERROR:
        return "application_error";
    case OSSL_QUIC_ERR_CRYPTO_BUFFER_EXCEEDED:
        return "crypto_buffer_exceeded";
    case OSSL_QUIC_ERR_KEY_UPDATE_ERROR:
        return "key_update_error";
    case OSSL_QUIC_ERR_AEAD_LIMIT_REACHED:
        return "aead_limit_reached";
    case OSSL_QUIC_ERR_NO_VIABLE_PATH:
        return "no_viable_path";
    default:
        return NULL;
    }
}
#endif

void ossl_qlog_event_connectivity_connection_closed(QLOG *qlog,
    const QUIC_TERMINATE_CAUSE *tcause)
{
#ifndef OPENSSL_NO_QLOG
    QLOG_EVENT_BEGIN(qlog, connectivity, connection_closed)
    QLOG_STR("owner", tcause->remote ? "remote" : "local");
    if (tcause->app) {
        QLOG_U64("application_code", tcause->error_code);
    } else {
        const char *m = quic_err_to_qlog(tcause->error_code);
        char ce[32];

        if (tcause->error_code >= OSSL_QUIC_ERR_CRYPTO_ERR_BEGIN
            && tcause->error_code <= OSSL_QUIC_ERR_CRYPTO_ERR_END) {
            BIO_snprintf(ce, sizeof(ce), "crypto_error_0x%03llx",
                (unsigned long long)tcause->error_code);
            m = ce;
        }
        /* TODO(QLOG FUTURE): Consider adding ERR information in the output. */

        if (m != NULL)
            QLOG_STR("connection_code", m);
        else
            QLOG_U64("connection_code", tcause->error_code);
    }

    QLOG_STR_LEN("reason", tcause->reason, tcause->reason_len);
    QLOG_EVENT_END()
#endif
}

#ifndef OPENSSL_NO_QLOG
static const char *quic_pkt_type_to_qlog(uint32_t pkt_type)
{
    switch (pkt_type) {
    case QUIC_PKT_TYPE_INITIAL:
        return "initial";
    case QUIC_PKT_TYPE_HANDSHAKE:
        return "handshake";
    case QUIC_PKT_TYPE_0RTT:
        return "0RTT";
    case QUIC_PKT_TYPE_1RTT:
        return "1RTT";
    case QUIC_PKT_TYPE_VERSION_NEG:
        return "version_negotiation";
    case QUIC_PKT_TYPE_RETRY:
        return "retry";
    default:
        return "unknown";
    }
}
#endif

void ossl_qlog_event_recovery_packet_lost(QLOG *qlog,
    const QUIC_TXPIM_PKT *tpkt)
{
#ifndef OPENSSL_NO_QLOG
    QLOG_EVENT_BEGIN(qlog, recovery, packet_lost)
    QLOG_BEGIN("header")
    QLOG_STR("packet_type", quic_pkt_type_to_qlog(tpkt->pkt_type));
    if (ossl_quic_pkt_type_has_pn(tpkt->pkt_type))
        QLOG_U64("packet_number", tpkt->ackm_pkt.pkt_num);
    QLOG_END()
    QLOG_EVENT_END()
#endif
}

#ifndef OPENSSL_NO_QLOG
#define MAX_ACK_RANGES 32

static void ignore_res(int x) { }

/*
 * For logging received packets, we need to parse all the frames in the packet
 * to log them. We should do this separately to the RXDP code because we want to
 * log the packet and its contents before we start to actually process it in
 * case it causes an error. We also in general don't want to do other
 * non-logging related work in the middle of an event logging transaction.
 * Reparsing packet data allows us to meet these needs while avoiding the need
 * to keep around bookkeeping data on what frames were in a packet, etc.
 *
 * For logging transmitted packets, we actually reuse the same code and reparse
 * the outgoing packet's payload. This again has the advantage that we only log
 * a packet when it is actually queued for transmission (and not if something
 * goes wrong before then) while avoiding the need to keep around bookkeeping
 * data on what frames it contained.
 */
static int log_frame_actual(QLOG *qlog_instance, PACKET *pkt,
    size_t *need_skip)
{
    uint64_t frame_type;
    OSSL_QUIC_FRAME_ACK ack;
    OSSL_QUIC_ACK_RANGE ack_ranges[MAX_ACK_RANGES];
    uint64_t num_ranges, total_ranges;
    size_t i;
    PACKET orig_pkt = *pkt;

    if (!ossl_quic_wire_peek_frame_header(pkt, &frame_type, NULL)) {
        *need_skip = SIZE_MAX;
        return 0;
    }

    /*
     * If something goes wrong decoding a frame we cannot log it as that frame
     * as we need to know how to decode it in order to be able to do so, but in
     * that case we log it as an unknown frame to assist with diagnosis.
     */
    switch (frame_type) {
    case OSSL_QUIC_FRAME_TYPE_PADDING:
        QLOG_STR("frame_type", "padding");
        QLOG_U64("payload_length",
            ossl_quic_wire_decode_padding(pkt));
        break;
    case OSSL_QUIC_FRAME_TYPE_PING:
        if (!ossl_quic_wire_decode_frame_ping(pkt))
            goto unknown;

        QLOG_STR("frame_type", "ping");
        break;
    case OSSL_QUIC_FRAME_TYPE_ACK_WITHOUT_ECN:
    case OSSL_QUIC_FRAME_TYPE_ACK_WITH_ECN:
        if (!ossl_quic_wire_peek_frame_ack_num_ranges(pkt, &num_ranges))
            goto unknown;

        ack.ack_ranges = ack_ranges;
        ack.num_ack_ranges = OSSL_NELEM(ack_ranges);
        if (!ossl_quic_wire_decode_frame_ack(pkt, 3, &ack, &total_ranges))
            goto unknown;

        QLOG_STR("frame_type", "ack");
        QLOG_U64("ack_delay", ossl_time2ms(ack.delay_time));
        if (ack.ecn_present) {
            QLOG_U64("ect1", ack.ect0);
            QLOG_U64("ect0", ack.ect1);
            QLOG_U64("ce", ack.ecnce);
        }
        QLOG_BEGIN_ARRAY("acked_ranges");
        for (i = 0; i < ack.num_ack_ranges; ++i) {
            QLOG_BEGIN_ARRAY(NULL)
            QLOG_U64(NULL, ack.ack_ranges[i].start);
            if (ack.ack_ranges[i].end != ack.ack_ranges[i].start)
                QLOG_U64(NULL, ack.ack_ranges[i].end);
            QLOG_END_ARRAY()
        }
        QLOG_END_ARRAY()
        break;
    case OSSL_QUIC_FRAME_TYPE_RESET_STREAM: {
        OSSL_QUIC_FRAME_RESET_STREAM f;

        if (!ossl_quic_wire_decode_frame_reset_stream(pkt, &f))
            goto unknown;

        QLOG_STR("frame_type", "reset_stream");
        QLOG_U64("stream_id", f.stream_id);
        QLOG_U64("error_code", f.app_error_code);
        QLOG_U64("final_size", f.final_size);
    } break;
    case OSSL_QUIC_FRAME_TYPE_STOP_SENDING: {
        OSSL_QUIC_FRAME_STOP_SENDING f;

        if (!ossl_quic_wire_decode_frame_stop_sending(pkt, &f))
            goto unknown;

        QLOG_STR("frame_type", "stop_sending");
        QLOG_U64("stream_id", f.stream_id);
        QLOG_U64("error_code", f.app_error_code);
    } break;
    case OSSL_QUIC_FRAME_TYPE_CRYPTO: {
        OSSL_QUIC_FRAME_CRYPTO f;

        if (!ossl_quic_wire_decode_frame_crypto(pkt, 1, &f))
            goto unknown;

        QLOG_STR("frame_type", "crypto");
        QLOG_U64("offset", f.offset);
        QLOG_U64("payload_length", f.len);
        *need_skip += (size_t)f.len;
    } break;
    case OSSL_QUIC_FRAME_TYPE_STREAM:
    case OSSL_QUIC_FRAME_TYPE_STREAM_FIN:
    case OSSL_QUIC_FRAME_TYPE_STREAM_LEN:
    case OSSL_QUIC_FRAME_TYPE_STREAM_LEN_FIN:
    case OSSL_QUIC_FRAME_TYPE_STREAM_OFF:
    case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_FIN:
    case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_LEN:
    case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_LEN_FIN: {
        OSSL_QUIC_FRAME_STREAM f;

        if (!ossl_quic_wire_decode_frame_stream(pkt, 1, &f))
            goto unknown;

        QLOG_STR("frame_type", "stream");
        QLOG_U64("stream_id", f.stream_id);
        QLOG_U64("offset", f.offset);
        QLOG_U64("payload_length", f.len);
        QLOG_BOOL("explicit_length", f.has_explicit_len);
        if (f.is_fin)
            QLOG_BOOL("fin", 1);
        *need_skip = f.has_explicit_len
            ? *need_skip + (size_t)f.len
            : SIZE_MAX;
    } break;
    case OSSL_QUIC_FRAME_TYPE_MAX_DATA: {
        uint64_t x;

        if (!ossl_quic_wire_decode_frame_max_data(pkt, &x))
            goto unknown;

        QLOG_STR("frame_type", "max_data");
        QLOG_U64("maximum", x);
    } break;
    case OSSL_QUIC_FRAME_TYPE_MAX_STREAMS_BIDI:
    case OSSL_QUIC_FRAME_TYPE_MAX_STREAMS_UNI: {
        uint64_t x;

        if (!ossl_quic_wire_decode_frame_max_streams(pkt, &x))
            goto unknown;

        QLOG_STR("frame_type", "max_streams");
        QLOG_STR("stream_type",
            frame_type == OSSL_QUIC_FRAME_TYPE_MAX_STREAMS_BIDI
                ? "bidirectional"
                : "unidirectional");
        QLOG_U64("maximum", x);
    } break;
    case OSSL_QUIC_FRAME_TYPE_MAX_STREAM_DATA: {
        uint64_t stream_id, max_data;

        if (!ossl_quic_wire_decode_frame_max_stream_data(pkt, &stream_id,
                &max_data))
            goto unknown;

        QLOG_STR("frame_type", "max_stream_data");
        QLOG_U64("stream_id", stream_id);
        QLOG_U64("maximum", max_data);
    } break;
    case OSSL_QUIC_FRAME_TYPE_PATH_CHALLENGE: {
        uint64_t challenge;

        if (!ossl_quic_wire_decode_frame_path_challenge(pkt, &challenge))
            goto unknown;

        QLOG_STR("frame_type", "path_challenge");
    } break;
    case OSSL_QUIC_FRAME_TYPE_PATH_RESPONSE: {
        uint64_t challenge;

        if (!ossl_quic_wire_decode_frame_path_response(pkt, &challenge))
            goto unknown;

        QLOG_STR("frame_type", "path_response");
    } break;
    case OSSL_QUIC_FRAME_TYPE_CONN_CLOSE_APP:
    case OSSL_QUIC_FRAME_TYPE_CONN_CLOSE_TRANSPORT: {
        OSSL_QUIC_FRAME_CONN_CLOSE f;

        if (!ossl_quic_wire_decode_frame_conn_close(pkt, &f))
            goto unknown;

        QLOG_STR("frame_type", "connection_close");
        QLOG_STR("error_space", f.is_app ? "application" : "transport");
        QLOG_U64("error_code_value", f.error_code);
        if (f.is_app)
            QLOG_U64("error_code", f.error_code);
        if (!f.is_app && f.frame_type != 0)
            QLOG_U64("trigger_frame_type", f.frame_type);
        QLOG_STR_LEN("reason", f.reason, f.reason_len);
    } break;
    case OSSL_QUIC_FRAME_TYPE_HANDSHAKE_DONE: {
        if (!ossl_quic_wire_decode_frame_handshake_done(pkt))
            goto unknown;

        QLOG_STR("frame_type", "handshake_done");
    } break;
    case OSSL_QUIC_FRAME_TYPE_NEW_CONN_ID: {
        OSSL_QUIC_FRAME_NEW_CONN_ID f;

        if (!ossl_quic_wire_decode_frame_new_conn_id(pkt, &f))
            goto unknown;

        QLOG_STR("frame_type", "new_connection_id");
        QLOG_U64("sequence_number", f.seq_num);
        QLOG_U64("retire_prior_to", f.retire_prior_to);
        QLOG_CID("connection_id", &f.conn_id);
        QLOG_BIN("stateless_reset_token",
            f.stateless_reset.token,
            sizeof(f.stateless_reset.token));
    } break;
    case OSSL_QUIC_FRAME_TYPE_RETIRE_CONN_ID: {
        uint64_t seq_num;

        if (!ossl_quic_wire_decode_frame_retire_conn_id(pkt, &seq_num))
            goto unknown;

        QLOG_STR("frame_type", "retire_connection_id");
        QLOG_U64("sequence_number", seq_num);
    } break;
    case OSSL_QUIC_FRAME_TYPE_DATA_BLOCKED: {
        uint64_t x;

        if (!ossl_quic_wire_decode_frame_data_blocked(pkt, &x))
            goto unknown;

        QLOG_STR("frame_type", "data_blocked");
        QLOG_U64("limit", x);
    } break;
    case OSSL_QUIC_FRAME_TYPE_STREAM_DATA_BLOCKED: {
        uint64_t stream_id, x;

        if (!ossl_quic_wire_decode_frame_stream_data_blocked(pkt,
                &stream_id,
                &x))
            goto unknown;

        QLOG_STR("frame_type", "stream_data_blocked");
        QLOG_U64("stream_id", stream_id);
        QLOG_U64("limit", x);
    } break;
    case OSSL_QUIC_FRAME_TYPE_STREAMS_BLOCKED_BIDI:
    case OSSL_QUIC_FRAME_TYPE_STREAMS_BLOCKED_UNI: {
        uint64_t x;

        if (!ossl_quic_wire_decode_frame_streams_blocked(pkt, &x))
            goto unknown;

        QLOG_STR("frame_type", "streams_blocked");
        QLOG_STR("stream_type",
            frame_type == OSSL_QUIC_FRAME_TYPE_STREAMS_BLOCKED_BIDI
                ? "bidirectional"
                : "unidirectional");
        QLOG_U64("limit", x);
    } break;
    case OSSL_QUIC_FRAME_TYPE_NEW_TOKEN: {
        const unsigned char *token;
        size_t token_len;

        if (!ossl_quic_wire_decode_frame_new_token(pkt, &token, &token_len))
            goto unknown;

        QLOG_STR("frame_type", "new_token");
        QLOG_BEGIN("token");
        QLOG_BEGIN("raw");
        QLOG_BIN("data", token, token_len);
        QLOG_END();
        QLOG_END();
    } break;
    default:
    unknown:
        QLOG_STR("frame_type", "unknown");
        QLOG_U64("frame_type_value", frame_type);

        /*
         * Can't continue scanning for frames in this case as the frame length
         * is unknown. We log the entire body of the rest of the packet payload
         * as the raw data of the frame.
         */
        QLOG_BEGIN("raw");
        QLOG_BIN("data", PACKET_data(&orig_pkt),
            PACKET_remaining(&orig_pkt));
        QLOG_END();
        ignore_res(PACKET_forward(pkt, PACKET_remaining(pkt)));
        break;
    }

    return 1;
}

static void log_frame(QLOG *qlog_instance, PACKET *pkt,
    size_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 need_skip = 0;

    for (i = 0; i < num_iovec; ++i) {
        if (!PACKET_buf_init(&pkt, iovec[i].buf, iovec[i].buf_len))
            return 0;

        while (PACKET_remaining(&pkt) > 0) {
            if (need_skip > 0) {
                size_t adv = need_skip;

                if (adv > PACKET_remaining(&pkt))
                    adv = PACKET_remaining(&pkt);

                if (!PACKET_forward(&pkt, adv))
                    return 0;

                need_skip -= adv;
                continue;
            }

            QLOG_BEGIN(NULL)
            {
                log_frame(qlog_instance, &pkt, &need_skip);
            }
            QLOG_END()
        }
    }

    return 1;
}

static void log_packet(QLOG *qlog_instance,
    const QUIC_PKT_HDR *hdr,
    QUIC_PN pn,
    const OSSL_QTX_IOVEC *iovec,
    size_t num_iovec,
    uint64_t datagram_id)
{
    const char *type_s;

    QLOG_BEGIN("header")
    type_s = quic_pkt_type_to_qlog(hdr->type);
    if (type_s == NULL)
        type_s = "unknown";

    QLOG_STR("packet_type", type_s);
    if (ossl_quic_pkt_type_has_pn(hdr->type))
        QLOG_U64("packet_number", pn);

    QLOG_CID("dcid", &hdr->dst_conn_id);
    if (ossl_quic_pkt_type_has_scid(hdr->type))
        QLOG_CID("scid", &hdr->src_conn_id);

    if (hdr->token_len > 0) {
        QLOG_BEGIN("token")
        QLOG_BEGIN("raw")
        QLOG_BIN("data", hdr->token, hdr->token_len);
        QLOG_END()
        QLOG_END()
    }
    /* TODO(QLOG FUTURE): flags, length */
    QLOG_END()
    QLOG_U64("datagram_id", datagram_id);

    if (ossl_quic_pkt_type_is_encrypted(hdr->type)) {
        QLOG_BEGIN_ARRAY("frames")
        log_frames(qlog_instance, iovec, num_iovec);
        QLOG_END_ARRAY()
    }
}

#endif

void ossl_qlog_event_transport_packet_sent(QLOG *qlog,
    const QUIC_PKT_HDR *hdr,
    QUIC_PN pn,
    const OSSL_QTX_IOVEC *iovec,
    size_t num_iovec,
    uint64_t datagram_id)
{
#ifndef OPENSSL_NO_QLOG
    QLOG_EVENT_BEGIN(qlog, transport, packet_sent)
    log_packet(qlog, hdr, pn, iovec, num_iovec, datagram_id);
    QLOG_EVENT_END()
#endif
}

void ossl_qlog_event_transport_packet_received(QLOG *qlog,
    const QUIC_PKT_HDR *hdr,
    QUIC_PN pn,
    const OSSL_QTX_IOVEC *iovec,
    size_t num_iovec,
    uint64_t datagram_id)
{
#ifndef OPENSSL_NO_QLOG
    QLOG_EVENT_BEGIN(qlog, transport, packet_received)
    log_packet(qlog, hdr, pn, iovec, num_iovec, datagram_id);
    QLOG_EVENT_END()
#endif
}

Coverage Report

Created: 2025-12-31 06:58

Line	Count	Source
1		/*
2		* Copyright 2023-2025 The OpenSSL Project Authors. All Rights Reserved.
3		*
4		* Licensed under the Apache License 2.0 (the "License"). You may not use
5		* this file except in compliance with the License. You can obtain a copy
6		* in the file LICENSE in the source distribution or at
7		* https://www.openssl.org/source/license.html
8		*/
9
10		#include "internal/qlog_event_helpers.h"
11		#include "internal/common.h"
12		#include "internal/packet.h"
13		#include "internal/quic_channel.h"
14		#include "internal/quic_error.h"
15
16		void ossl_qlog_event_connectivity_connection_started(QLOG *qlog,
17		const QUIC_CONN_ID *init_dcid)
18	50.4k	{
19	50.4k	#ifndef OPENSSL_NO_QLOG
20	50.4k	QLOG_EVENT_BEGIN(qlog, connectivity, connection_started)
21	0	QLOG_STR("protocol", "quic");
22	0	QLOG_CID("dst_cid", init_dcid);
23	0	QLOG_EVENT_END()
24	50.4k	#endif
25	50.4k	}
26
27		#ifndef OPENSSL_NO_QLOG
28		static const char *map_state_to_qlog(uint32_t state,
29		int handshake_complete,
30		int handshake_confirmed)
31	0	{
32	0	switch (state) {
33	0	default:
34	0	case QUIC_CHANNEL_STATE_IDLE:
35	0	return NULL;
36
37	0	case QUIC_CHANNEL_STATE_ACTIVE:
38	0	if (handshake_confirmed)
39	0	return "handshake_confirmed";
40	0	else if (handshake_complete)
41	0	return "handshake_complete";
42	0	else
43	0	return "attempted";
44
45	0	case QUIC_CHANNEL_STATE_TERMINATING_CLOSING:
46	0	return "closing";
47
48	0	case QUIC_CHANNEL_STATE_TERMINATING_DRAINING:
49	0	return "draining";
50
51	0	case QUIC_CHANNEL_STATE_TERMINATED:
52	0	return "closed";
53	0	}
54	0	}
55		#endif
56
57		void ossl_qlog_event_connectivity_connection_state_updated(QLOG *qlog,
58		uint32_t old_state,
59		uint32_t new_state,
60		int handshake_complete,
61		int handshake_confirmed)
62	111k	{
63	111k	#ifndef OPENSSL_NO_QLOG
64	111k	const char *state_s;
65
66	111k	QLOG_EVENT_BEGIN(qlog, connectivity, connection_state_updated)
67	0	state_s = map_state_to_qlog(new_state,
68	0	handshake_complete,
69	0	handshake_confirmed);
70
71	0	if (state_s != NULL)
72	0	QLOG_STR("state", state_s);
73	0	QLOG_EVENT_END()
74	111k	#endif
75	111k	}
76
77		#ifndef OPENSSL_NO_QLOG
78		static const char *quic_err_to_qlog(uint64_t error_code)
79	0	{
80	0	switch (error_code) {
81	0	case OSSL_QUIC_ERR_INTERNAL_ERROR:
82	0	return "internal_error";
83	0	case OSSL_QUIC_ERR_CONNECTION_REFUSED:
84	0	return "connection_refused";
85	0	case OSSL_QUIC_ERR_FLOW_CONTROL_ERROR:
86	0	return "flow_control_error";
87	0	case OSSL_QUIC_ERR_STREAM_LIMIT_ERROR:
88	0	return "stream_limit_error";
89	0	case OSSL_QUIC_ERR_STREAM_STATE_ERROR:
90	0	return "stream_state_error";
91	0	case OSSL_QUIC_ERR_FINAL_SIZE_ERROR:
92	0	return "final_size_error";
93	0	case OSSL_QUIC_ERR_FRAME_ENCODING_ERROR:
94	0	return "frame_encoding_error";
95	0	case OSSL_QUIC_ERR_TRANSPORT_PARAMETER_ERROR:
96	0	return "transport_parameter_error";
97	0	case OSSL_QUIC_ERR_CONNECTION_ID_LIMIT_ERROR:
98	0	return "connection_id_limit_error";
99	0	case OSSL_QUIC_ERR_PROTOCOL_VIOLATION:
100	0	return "protocol_violation";
101	0	case OSSL_QUIC_ERR_INVALID_TOKEN:
102	0	return "invalid_token";
103	0	case OSSL_QUIC_ERR_APPLICATION_ERROR:
104	0	return "application_error";
105	0	case OSSL_QUIC_ERR_CRYPTO_BUFFER_EXCEEDED:
106	0	return "crypto_buffer_exceeded";
107	0	case OSSL_QUIC_ERR_KEY_UPDATE_ERROR:
108	0	return "key_update_error";
109	0	case OSSL_QUIC_ERR_AEAD_LIMIT_REACHED:
110	0	return "aead_limit_reached";
111	0	case OSSL_QUIC_ERR_NO_VIABLE_PATH:
112	0	return "no_viable_path";
113	0	default:
114	0	return NULL;
115	0	}
116	0	}
117		#endif
118
119		void ossl_qlog_event_connectivity_connection_closed(QLOG *qlog,
120		const QUIC_TERMINATE_CAUSE *tcause)
121	25.7k	{
122	25.7k	#ifndef OPENSSL_NO_QLOG
123	25.7k	QLOG_EVENT_BEGIN(qlog, connectivity, connection_closed)
124	0	QLOG_STR("owner", tcause->remote ? "remote" : "local");
125	0	if (tcause->app) {
126	0	QLOG_U64("application_code", tcause->error_code);
127	0	} else {
128	0	const char *m = quic_err_to_qlog(tcause->error_code);
129	0	char ce[32];
130
131	0	if (tcause->error_code >= OSSL_QUIC_ERR_CRYPTO_ERR_BEGIN
132	0	&& tcause->error_code <= OSSL_QUIC_ERR_CRYPTO_ERR_END) {
133	0	BIO_snprintf(ce, sizeof(ce), "crypto_error_0x%03llx",
134	0	(unsigned long long)tcause->error_code);
135	0	m = ce;
136	0	}
137		/* TODO(QLOG FUTURE): Consider adding ERR information in the output. */
138
139	0	if (m != NULL)
140	0	QLOG_STR("connection_code", m);
141	0	else
142	0	QLOG_U64("connection_code", tcause->error_code);
143	0	}
144
145	0	QLOG_STR_LEN("reason", tcause->reason, tcause->reason_len);
146	0	QLOG_EVENT_END()
147	25.7k	#endif
148	25.7k	}
149
150		#ifndef OPENSSL_NO_QLOG
151		static const char *quic_pkt_type_to_qlog(uint32_t pkt_type)
152	0	{
153	0	switch (pkt_type) {
154	0	case QUIC_PKT_TYPE_INITIAL:
155	0	return "initial";
156	0	case QUIC_PKT_TYPE_HANDSHAKE:
157	0	return "handshake";
158	0	case QUIC_PKT_TYPE_0RTT:
159	0	return "0RTT";
160	0	case QUIC_PKT_TYPE_1RTT:
161	0	return "1RTT";
162	0	case QUIC_PKT_TYPE_VERSION_NEG:
163	0	return "version_negotiation";
164	0	case QUIC_PKT_TYPE_RETRY:
165	0	return "retry";
166	0	default:
167	0	return "unknown";
168	0	}
169	0	}
170		#endif
171
172		void ossl_qlog_event_recovery_packet_lost(QLOG *qlog,
173		const QUIC_TXPIM_PKT *tpkt)
174	140k	{
175	140k	#ifndef OPENSSL_NO_QLOG
176	140k	QLOG_EVENT_BEGIN(qlog, recovery, packet_lost)
177	0	QLOG_BEGIN("header")
178	0	QLOG_STR("packet_type", quic_pkt_type_to_qlog(tpkt->pkt_type));
179	0	if (ossl_quic_pkt_type_has_pn(tpkt->pkt_type))
180	0	QLOG_U64("packet_number", tpkt->ackm_pkt.pkt_num);
181	0	QLOG_END()
182	0	QLOG_EVENT_END()
183	140k	#endif
184	140k	}
185
186		#ifndef OPENSSL_NO_QLOG
187		#define MAX_ACK_RANGES 32
188
189	0	static void ignore_res(int x) { }
190
191		/*
192		* For logging received packets, we need to parse all the frames in the packet
193		* to log them. We should do this separately to the RXDP code because we want to
194		* log the packet and its contents before we start to actually process it in
195		* case it causes an error. We also in general don't want to do other
196		* non-logging related work in the middle of an event logging transaction.
197		* Reparsing packet data allows us to meet these needs while avoiding the need
198		* to keep around bookkeeping data on what frames were in a packet, etc.
199		*
200		* For logging transmitted packets, we actually reuse the same code and reparse
201		* the outgoing packet's payload. This again has the advantage that we only log
202		* a packet when it is actually queued for transmission (and not if something
203		* goes wrong before then) while avoiding the need to keep around bookkeeping
204		* data on what frames it contained.
205		*/
206		static int log_frame_actual(QLOG qlog_instance, PACKET pkt,
207		size_t *need_skip)
208	0	{
209	0	uint64_t frame_type;
210	0	OSSL_QUIC_FRAME_ACK ack;
211	0	OSSL_QUIC_ACK_RANGE ack_ranges[MAX_ACK_RANGES];
212	0	uint64_t num_ranges, total_ranges;
213	0	size_t i;
214	0	PACKET orig_pkt = *pkt;
215
216	0	if (!ossl_quic_wire_peek_frame_header(pkt, &frame_type, NULL)) {
217	0	*need_skip = SIZE_MAX;
218	0	return 0;
219	0	}
220
221		/*
222		* If something goes wrong decoding a frame we cannot log it as that frame
223		* as we need to know how to decode it in order to be able to do so, but in
224		* that case we log it as an unknown frame to assist with diagnosis.
225		*/
226	0	switch (frame_type) {
227	0	case OSSL_QUIC_FRAME_TYPE_PADDING:
228	0	QLOG_STR("frame_type", "padding");
229	0	QLOG_U64("payload_length",
230	0	ossl_quic_wire_decode_padding(pkt));
231	0	break;
232	0	case OSSL_QUIC_FRAME_TYPE_PING:
233	0	if (!ossl_quic_wire_decode_frame_ping(pkt))
234	0	goto unknown;
235
236	0	QLOG_STR("frame_type", "ping");
237	0	break;
238	0	case OSSL_QUIC_FRAME_TYPE_ACK_WITHOUT_ECN:
239	0	case OSSL_QUIC_FRAME_TYPE_ACK_WITH_ECN:
240	0	if (!ossl_quic_wire_peek_frame_ack_num_ranges(pkt, &num_ranges))
241	0	goto unknown;
242
243	0	ack.ack_ranges = ack_ranges;
244	0	ack.num_ack_ranges = OSSL_NELEM(ack_ranges);
245	0	if (!ossl_quic_wire_decode_frame_ack(pkt, 3, &ack, &total_ranges))
246	0	goto unknown;
247
248	0	QLOG_STR("frame_type", "ack");
249	0	QLOG_U64("ack_delay", ossl_time2ms(ack.delay_time));
250	0	if (ack.ecn_present) {
251	0	QLOG_U64("ect1", ack.ect0);
252	0	QLOG_U64("ect0", ack.ect1);
253	0	QLOG_U64("ce", ack.ecnce);
254	0	}
255	0	QLOG_BEGIN_ARRAY("acked_ranges");
256	0	for (i = 0; i < ack.num_ack_ranges; ++i) {
257	0	QLOG_BEGIN_ARRAY(NULL)
258	0	QLOG_U64(NULL, ack.ack_ranges[i].start);
259	0	if (ack.ack_ranges[i].end != ack.ack_ranges[i].start)
260	0	QLOG_U64(NULL, ack.ack_ranges[i].end);
261	0	QLOG_END_ARRAY()
262	0	}
263	0	QLOG_END_ARRAY()
264	0	break;
265	0	case OSSL_QUIC_FRAME_TYPE_RESET_STREAM: {
266	0	OSSL_QUIC_FRAME_RESET_STREAM f;
267
268	0	if (!ossl_quic_wire_decode_frame_reset_stream(pkt, &f))
269	0	goto unknown;
270
271	0	QLOG_STR("frame_type", "reset_stream");
272	0	QLOG_U64("stream_id", f.stream_id);
273	0	QLOG_U64("error_code", f.app_error_code);
274	0	QLOG_U64("final_size", f.final_size);
275	0	} break;
276	0	case OSSL_QUIC_FRAME_TYPE_STOP_SENDING: {
277	0	OSSL_QUIC_FRAME_STOP_SENDING f;
278
279	0	if (!ossl_quic_wire_decode_frame_stop_sending(pkt, &f))
280	0	goto unknown;
281
282	0	QLOG_STR("frame_type", "stop_sending");
283	0	QLOG_U64("stream_id", f.stream_id);
284	0	QLOG_U64("error_code", f.app_error_code);
285	0	} break;
286	0	case OSSL_QUIC_FRAME_TYPE_CRYPTO: {
287	0	OSSL_QUIC_FRAME_CRYPTO f;
288
289	0	if (!ossl_quic_wire_decode_frame_crypto(pkt, 1, &f))
290	0	goto unknown;
291
292	0	QLOG_STR("frame_type", "crypto");
293	0	QLOG_U64("offset", f.offset);
294	0	QLOG_U64("payload_length", f.len);
295	0	*need_skip += (size_t)f.len;
296	0	} break;
297	0	case OSSL_QUIC_FRAME_TYPE_STREAM:
298	0	case OSSL_QUIC_FRAME_TYPE_STREAM_FIN:
299	0	case OSSL_QUIC_FRAME_TYPE_STREAM_LEN:
300	0	case OSSL_QUIC_FRAME_TYPE_STREAM_LEN_FIN:
301	0	case OSSL_QUIC_FRAME_TYPE_STREAM_OFF:
302	0	case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_FIN:
303	0	case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_LEN:
304	0	case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_LEN_FIN: {
305	0	OSSL_QUIC_FRAME_STREAM f;
306
307	0	if (!ossl_quic_wire_decode_frame_stream(pkt, 1, &f))
308	0	goto unknown;
309
310	0	QLOG_STR("frame_type", "stream");
311	0	QLOG_U64("stream_id", f.stream_id);
312	0	QLOG_U64("offset", f.offset);
313	0	QLOG_U64("payload_length", f.len);
314	0	QLOG_BOOL("explicit_length", f.has_explicit_len);
315	0	if (f.is_fin)
316	0	QLOG_BOOL("fin", 1);
317	0	*need_skip = f.has_explicit_len
318	0	? *need_skip + (size_t)f.len
319	0	: SIZE_MAX;
320	0	} break;
321	0	case OSSL_QUIC_FRAME_TYPE_MAX_DATA: {
322	0	uint64_t x;
323
324	0	if (!ossl_quic_wire_decode_frame_max_data(pkt, &x))
325	0	goto unknown;
326
327	0	QLOG_STR("frame_type", "max_data");
328	0	QLOG_U64("maximum", x);
329	0	} break;
330	0	case OSSL_QUIC_FRAME_TYPE_MAX_STREAMS_BIDI:
331	0	case OSSL_QUIC_FRAME_TYPE_MAX_STREAMS_UNI: {
332	0	uint64_t x;
333
334	0	if (!ossl_quic_wire_decode_frame_max_streams(pkt, &x))
335	0	goto unknown;
336
337	0	QLOG_STR("frame_type", "max_streams");
338	0	QLOG_STR("stream_type",
339	0	frame_type == OSSL_QUIC_FRAME_TYPE_MAX_STREAMS_BIDI
340	0	? "bidirectional"
341	0	: "unidirectional");
342	0	QLOG_U64("maximum", x);
343	0	} break;
344	0	case OSSL_QUIC_FRAME_TYPE_MAX_STREAM_DATA: {
345	0	uint64_t stream_id, max_data;
346
347	0	if (!ossl_quic_wire_decode_frame_max_stream_data(pkt, &stream_id,
348	0	&max_data))
349	0	goto unknown;
350
351	0	QLOG_STR("frame_type", "max_stream_data");
352	0	QLOG_U64("stream_id", stream_id);
353	0	QLOG_U64("maximum", max_data);
354	0	} break;
355	0	case OSSL_QUIC_FRAME_TYPE_PATH_CHALLENGE: {
356	0	uint64_t challenge;
357
358	0	if (!ossl_quic_wire_decode_frame_path_challenge(pkt, &challenge))
359	0	goto unknown;
360
361	0	QLOG_STR("frame_type", "path_challenge");
362	0	} break;
363	0	case OSSL_QUIC_FRAME_TYPE_PATH_RESPONSE: {
364	0	uint64_t challenge;
365
366	0	if (!ossl_quic_wire_decode_frame_path_response(pkt, &challenge))
367	0	goto unknown;
368
369	0	QLOG_STR("frame_type", "path_response");
370	0	} break;
371	0	case OSSL_QUIC_FRAME_TYPE_CONN_CLOSE_APP:
372	0	case OSSL_QUIC_FRAME_TYPE_CONN_CLOSE_TRANSPORT: {
373	0	OSSL_QUIC_FRAME_CONN_CLOSE f;
374
375	0	if (!ossl_quic_wire_decode_frame_conn_close(pkt, &f))
376	0	goto unknown;
377
378	0	QLOG_STR("frame_type", "connection_close");
379	0	QLOG_STR("error_space", f.is_app ? "application" : "transport");
380	0	QLOG_U64("error_code_value", f.error_code);
381	0	if (f.is_app)
382	0	QLOG_U64("error_code", f.error_code);
383	0	if (!f.is_app && f.frame_type != 0)
384	0	QLOG_U64("trigger_frame_type", f.frame_type);
385	0	QLOG_STR_LEN("reason", f.reason, f.reason_len);
386	0	} break;
387	0	case OSSL_QUIC_FRAME_TYPE_HANDSHAKE_DONE: {
388	0	if (!ossl_quic_wire_decode_frame_handshake_done(pkt))
389	0	goto unknown;
390
391	0	QLOG_STR("frame_type", "handshake_done");
392	0	} break;
393	0	case OSSL_QUIC_FRAME_TYPE_NEW_CONN_ID: {
394	0	OSSL_QUIC_FRAME_NEW_CONN_ID f;
395
396	0	if (!ossl_quic_wire_decode_frame_new_conn_id(pkt, &f))
397	0	goto unknown;
398
399	0	QLOG_STR("frame_type", "new_connection_id");
400	0	QLOG_U64("sequence_number", f.seq_num);
401	0	QLOG_U64("retire_prior_to", f.retire_prior_to);
402	0	QLOG_CID("connection_id", &f.conn_id);
403	0	QLOG_BIN("stateless_reset_token",
404	0	f.stateless_reset.token,
405	0	sizeof(f.stateless_reset.token));
406	0	} break;
407	0	case OSSL_QUIC_FRAME_TYPE_RETIRE_CONN_ID: {
408	0	uint64_t seq_num;
409
410	0	if (!ossl_quic_wire_decode_frame_retire_conn_id(pkt, &seq_num))
411	0	goto unknown;
412
413	0	QLOG_STR("frame_type", "retire_connection_id");
414	0	QLOG_U64("sequence_number", seq_num);
415	0	} break;
416	0	case OSSL_QUIC_FRAME_TYPE_DATA_BLOCKED: {
417	0	uint64_t x;
418
419	0	if (!ossl_quic_wire_decode_frame_data_blocked(pkt, &x))
420	0	goto unknown;
421
422	0	QLOG_STR("frame_type", "data_blocked");
423	0	QLOG_U64("limit", x);
424	0	} break;
425	0	case OSSL_QUIC_FRAME_TYPE_STREAM_DATA_BLOCKED: {
426	0	uint64_t stream_id, x;
427
428	0	if (!ossl_quic_wire_decode_frame_stream_data_blocked(pkt,
429	0	&stream_id,
430	0	&x))
431	0	goto unknown;
432
433	0	QLOG_STR("frame_type", "stream_data_blocked");
434	0	QLOG_U64("stream_id", stream_id);
435	0	QLOG_U64("limit", x);
436	0	} break;
437	0	case OSSL_QUIC_FRAME_TYPE_STREAMS_BLOCKED_BIDI:
438	0	case OSSL_QUIC_FRAME_TYPE_STREAMS_BLOCKED_UNI: {
439	0	uint64_t x;
440
441	0	if (!ossl_quic_wire_decode_frame_streams_blocked(pkt, &x))
442	0	goto unknown;
443
444	0	QLOG_STR("frame_type", "streams_blocked");
445	0	QLOG_STR("stream_type",
446	0	frame_type == OSSL_QUIC_FRAME_TYPE_STREAMS_BLOCKED_BIDI
447	0	? "bidirectional"
448	0	: "unidirectional");
449	0	QLOG_U64("limit", x);
450	0	} break;
451	0	case OSSL_QUIC_FRAME_TYPE_NEW_TOKEN: {
452	0	const unsigned char *token;
453	0	size_t token_len;
454
455	0	if (!ossl_quic_wire_decode_frame_new_token(pkt, &token, &token_len))
456	0	goto unknown;
457
458	0	QLOG_STR("frame_type", "new_token");
459	0	QLOG_BEGIN("token");
460	0	QLOG_BEGIN("raw");
461	0	QLOG_BIN("data", token, token_len);
462	0	QLOG_END();
463	0	QLOG_END();
464	0	} break;
465	0	default:
466	0	unknown:
467	0	QLOG_STR("frame_type", "unknown");
468	0	QLOG_U64("frame_type_value", frame_type);
469
470		/*
471		* Can't continue scanning for frames in this case as the frame length
472		* is unknown. We log the entire body of the rest of the packet payload
473		* as the raw data of the frame.
474		*/
475	0	QLOG_BEGIN("raw");
476	0	QLOG_BIN("data", PACKET_data(&orig_pkt),
477	0	PACKET_remaining(&orig_pkt));
478	0	QLOG_END();
479	0	ignore_res(PACKET_forward(pkt, PACKET_remaining(pkt)));
480	0	break;
481	0	}
482
483	0	return 1;
484	0	}
485
486		static void log_frame(QLOG qlog_instance, PACKET pkt,
487		size_t *need_skip)
488	0	{
489	0	size_t rem_before, rem_after;
490
491	0	rem_before = PACKET_remaining(pkt);
492
493	0	if (!log_frame_actual(qlog_instance, pkt, need_skip))
494	0	return;
495
496	0	rem_after = PACKET_remaining(pkt);
497	0	QLOG_U64("length", rem_before - rem_after);
498	0	}
499
500		static int log_frames(QLOG *qlog_instance,
501		const OSSL_QTX_IOVEC *iovec,
502		size_t num_iovec)
503	0	{
504	0	size_t i;
505	0	PACKET pkt;
506	0	size_t need_skip = 0;
507
508	0	for (i = 0; i < num_iovec; ++i) {
509	0	if (!PACKET_buf_init(&pkt, iovec[i].buf, iovec[i].buf_len))
510	0	return 0;
511
512	0	while (PACKET_remaining(&pkt) > 0) {
513	0	if (need_skip > 0) {
514	0	size_t adv = need_skip;
515
516	0	if (adv > PACKET_remaining(&pkt))
517	0	adv = PACKET_remaining(&pkt);
518
519	0	if (!PACKET_forward(&pkt, adv))
520	0	return 0;
521
522	0	need_skip -= adv;
523	0	continue;
524	0	}
525
526	0	QLOG_BEGIN(NULL)
527	0	{
528	0	log_frame(qlog_instance, &pkt, &need_skip);
529	0	}
530	0	QLOG_END()
531	0	}
532	0	}
533
534	0	return 1;
535	0	}
536
537		static void log_packet(QLOG *qlog_instance,
538		const QUIC_PKT_HDR *hdr,
539		QUIC_PN pn,
540		const OSSL_QTX_IOVEC *iovec,
541		size_t num_iovec,
542		uint64_t datagram_id)
543	0	{
544	0	const char *type_s;
545
546	0	QLOG_BEGIN("header")
547	0	type_s = quic_pkt_type_to_qlog(hdr->type);
548	0	if (type_s == NULL)
549	0	type_s = "unknown";
550
551	0	QLOG_STR("packet_type", type_s);
552	0	if (ossl_quic_pkt_type_has_pn(hdr->type))
553	0	QLOG_U64("packet_number", pn);
554
555	0	QLOG_CID("dcid", &hdr->dst_conn_id);
556	0	if (ossl_quic_pkt_type_has_scid(hdr->type))
557	0	QLOG_CID("scid", &hdr->src_conn_id);
558
559	0	if (hdr->token_len > 0) {
560	0	QLOG_BEGIN("token")
561	0	QLOG_BEGIN("raw")
562	0	QLOG_BIN("data", hdr->token, hdr->token_len);
563	0	QLOG_END()
564	0	QLOG_END()
565	0	}
566		/* TODO(QLOG FUTURE): flags, length */
567	0	QLOG_END()
568	0	QLOG_U64("datagram_id", datagram_id);
569
570	0	if (ossl_quic_pkt_type_is_encrypted(hdr->type)) {
571	0	QLOG_BEGIN_ARRAY("frames")
572	0	log_frames(qlog_instance, iovec, num_iovec);
573	0	QLOG_END_ARRAY()
574	0	}
575	0	}
576
577		#endif
578
579		void ossl_qlog_event_transport_packet_sent(QLOG *qlog,
580		const QUIC_PKT_HDR *hdr,
581		QUIC_PN pn,
582		const OSSL_QTX_IOVEC *iovec,
583		size_t num_iovec,
584		uint64_t datagram_id)
585	2.07M	{
586	2.07M	#ifndef OPENSSL_NO_QLOG
587	2.07M	QLOG_EVENT_BEGIN(qlog, transport, packet_sent)
588	0	log_packet(qlog, hdr, pn, iovec, num_iovec, datagram_id);
589	0	QLOG_EVENT_END()
590	2.07M	#endif
591	2.07M	}
592
593		void ossl_qlog_event_transport_packet_received(QLOG *qlog,
594		const QUIC_PKT_HDR *hdr,
595		QUIC_PN pn,
596		const OSSL_QTX_IOVEC *iovec,
597		size_t num_iovec,
598		uint64_t datagram_id)
599	1.48M	{
600	1.48M	#ifndef OPENSSL_NO_QLOG
601	1.48M	QLOG_EVENT_BEGIN(qlog, transport, packet_received)
602	0	log_packet(qlog, hdr, pn, iovec, num_iovec, datagram_id);
603	0	QLOG_EVENT_END()
604	1.48M	#endif
605	1.48M	}