lsquic_ev_log.c revision 7d09751d
17d09751dSDmitri Tikhonov/* Copyright (c) 2017 - 2020 LiteSpeed Technologies Inc.  See LICENSE. */
2461e84d8SAmol Deshpande#ifndef WIN32
350aadb33SDmitri Tikhonov#include <arpa/inet.h>
4461e84d8SAmol Deshpande#else
5461e84d8SAmol Deshpande#include <vc_compat.h>
6461e84d8SAmol Deshpande#endif
750aadb33SDmitri Tikhonov#include <errno.h>
850aadb33SDmitri Tikhonov#include <inttypes.h>
950aadb33SDmitri Tikhonov#include <stdlib.h>
1050aadb33SDmitri Tikhonov#include <string.h>
11461e84d8SAmol Deshpande#include <sys/queue.h>
1250aadb33SDmitri Tikhonov
1350aadb33SDmitri Tikhonov#include "lsquic.h"
1450aadb33SDmitri Tikhonov#include "lsquic_types.h"
1550aadb33SDmitri Tikhonov#include "lsquic_int_types.h"
1650aadb33SDmitri Tikhonov#include "lsquic_packet_common.h"
175392f7a3SLiteSpeed Tech#include "lsquic_packet_gquic.h"
1850aadb33SDmitri Tikhonov#include "lsquic_packet_in.h"
1950aadb33SDmitri Tikhonov#include "lsquic_packet_out.h"
2050aadb33SDmitri Tikhonov#include "lsquic_parse.h"
2150aadb33SDmitri Tikhonov#include "lsquic_frame_common.h"
223b55e6aeSDmitri Tikhonov#include "lsquic_headers.h"
239626cfc2SDmitri Tikhonov#include "lsquic_str.h"
245392f7a3SLiteSpeed Tech#include "lsquic_frame_reader.h"
255392f7a3SLiteSpeed Tech#include "lsquic_enc_sess.h"
2650aadb33SDmitri Tikhonov#include "lsquic_ev_log.h"
275392f7a3SLiteSpeed Tech#include "lsquic_sizes.h"
285392f7a3SLiteSpeed Tech#include "lsquic_trans_params.h"
295392f7a3SLiteSpeed Tech#include "lsquic_util.h"
305392f7a3SLiteSpeed Tech#include "lsquic_hash.h"
315392f7a3SLiteSpeed Tech#include "lsquic_conn.h"
3250aadb33SDmitri Tikhonov
3350aadb33SDmitri Tikhonov#define LSQUIC_LOGGER_MODULE LSQLM_EVENT
3450aadb33SDmitri Tikhonov#include "lsquic_logger.h"
3550aadb33SDmitri Tikhonov
3650aadb33SDmitri Tikhonov
3750aadb33SDmitri Tikhonov/*  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^  */
3850aadb33SDmitri Tikhonov/*  ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||  */
3950aadb33SDmitri Tikhonov/* Messages that do not include connection ID go above this point */
4050aadb33SDmitri Tikhonov
4150aadb33SDmitri Tikhonov#define LSQUIC_LOG_CONN_ID cid
42461e84d8SAmol Deshpande#define LCID(...) LSQ_LOG2(LSQ_LOG_DEBUG, __VA_ARGS__)   /* LCID: log with CID */
4350aadb33SDmitri Tikhonov
4450aadb33SDmitri Tikhonov/* Messages that are to include connection ID go below this point */
4550aadb33SDmitri Tikhonov/*  ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||  */
4650aadb33SDmitri Tikhonov/*  VVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVVV  */
4750aadb33SDmitri Tikhonov
4850aadb33SDmitri Tikhonovvoid
495392f7a3SLiteSpeed Techlsquic_ev_log_packet_in (const lsquic_cid_t *cid,
505392f7a3SLiteSpeed Tech                                        const lsquic_packet_in_t *packet_in)
5150aadb33SDmitri Tikhonov{
529626cfc2SDmitri Tikhonov    switch (packet_in->pi_flags & (
535392f7a3SLiteSpeed Tech                                   PI_FROM_MINI|
549626cfc2SDmitri Tikhonov                                                PI_GQUIC))
559626cfc2SDmitri Tikhonov    {
565392f7a3SLiteSpeed Tech    case PI_FROM_MINI|PI_GQUIC:
575392f7a3SLiteSpeed Tech        LCID("packet in: %"PRIu64" (from mini)", packet_in->pi_packno);
585392f7a3SLiteSpeed Tech        break;
595392f7a3SLiteSpeed Tech    case PI_FROM_MINI:
605392f7a3SLiteSpeed Tech        LCID("packet in: %"PRIu64" (from mini), type: %s, ecn: %u",
615392f7a3SLiteSpeed Tech            packet_in->pi_packno, lsquic_hety2str[packet_in->pi_header_type],
625392f7a3SLiteSpeed Tech            lsquic_packet_in_ecn(packet_in));
635392f7a3SLiteSpeed Tech        break;
649626cfc2SDmitri Tikhonov    case PI_GQUIC:
655392f7a3SLiteSpeed Tech        LCID("packet in: %"PRIu64", size: %u", packet_in->pi_packno,
665392f7a3SLiteSpeed Tech            (unsigned) (packet_in->pi_data_sz + GQUIC_PACKET_HASH_SZ));
679626cfc2SDmitri Tikhonov        break;
689626cfc2SDmitri Tikhonov    default:
6902b6086dSDmitri Tikhonov        if (packet_in->pi_flags & PI_LOG_QL_BITS)
7002b6086dSDmitri Tikhonov            LCID("packet in: %"PRIu64", type: %s, size: %u; ecn: %u, spin: %d; "
7102b6086dSDmitri Tikhonov                "path: %hhu; Q: %d; L: %d",
7202b6086dSDmitri Tikhonov                packet_in->pi_packno, lsquic_hety2str[packet_in->pi_header_type],
7302b6086dSDmitri Tikhonov                (unsigned) (packet_in->pi_data_sz + IQUIC_TAG_LEN),
7402b6086dSDmitri Tikhonov                lsquic_packet_in_ecn(packet_in),
7502b6086dSDmitri Tikhonov                /* spin bit value is only valid for short packet headers */
7602b6086dSDmitri Tikhonov                lsquic_packet_in_spin_bit(packet_in), packet_in->pi_path_id,
7702b6086dSDmitri Tikhonov                ((packet_in->pi_flags & PI_SQUARE_BIT) > 0),
7802b6086dSDmitri Tikhonov                ((packet_in->pi_flags & PI_LOSS_BIT) > 0));
7902b6086dSDmitri Tikhonov        else
8002b6086dSDmitri Tikhonov            LCID("packet in: %"PRIu64", type: %s, size: %u; ecn: %u, spin: %d; "
8102b6086dSDmitri Tikhonov                "path: %hhu",
8202b6086dSDmitri Tikhonov                packet_in->pi_packno, lsquic_hety2str[packet_in->pi_header_type],
8302b6086dSDmitri Tikhonov                (unsigned) (packet_in->pi_data_sz + IQUIC_TAG_LEN),
8402b6086dSDmitri Tikhonov                lsquic_packet_in_ecn(packet_in),
8502b6086dSDmitri Tikhonov                /* spin bit value is only valid for short packet headers */
8602b6086dSDmitri Tikhonov                lsquic_packet_in_spin_bit(packet_in), packet_in->pi_path_id);
879626cfc2SDmitri Tikhonov        break;
889626cfc2SDmitri Tikhonov    }
8950aadb33SDmitri Tikhonov}
9050aadb33SDmitri Tikhonov
9150aadb33SDmitri Tikhonov
9250aadb33SDmitri Tikhonovvoid
935392f7a3SLiteSpeed Techlsquic_ev_log_ack_frame_in (const lsquic_cid_t *cid,
945392f7a3SLiteSpeed Tech                                        const struct ack_info *acki)
9550aadb33SDmitri Tikhonov{
96de46bf2fSDmitri Tikhonov    char buf[MAX_ACKI_STR_SZ];
9750aadb33SDmitri Tikhonov
98de46bf2fSDmitri Tikhonov    lsquic_acki2str(acki, buf, sizeof(buf));
99de46bf2fSDmitri Tikhonov    LCID("ACK frame in: %s", buf);
10050aadb33SDmitri Tikhonov}
10150aadb33SDmitri Tikhonov
10250aadb33SDmitri Tikhonov
10350aadb33SDmitri Tikhonovvoid
1045392f7a3SLiteSpeed Techlsquic_ev_log_stream_frame_in (const lsquic_cid_t *cid,
10550aadb33SDmitri Tikhonov                                        const struct stream_frame *frame)
10650aadb33SDmitri Tikhonov{
1075392f7a3SLiteSpeed Tech    LCID("STREAM frame in: stream %"PRIu64"; offset %"PRIu64"; size %"PRIu16
10850aadb33SDmitri Tikhonov        "; fin: %d", frame->stream_id, frame->data_frame.df_offset,
10950aadb33SDmitri Tikhonov        frame->data_frame.df_size, (int) frame->data_frame.df_fin);
11050aadb33SDmitri Tikhonov}
11150aadb33SDmitri Tikhonov
11250aadb33SDmitri Tikhonov
11350aadb33SDmitri Tikhonovvoid
1145392f7a3SLiteSpeed Techlsquic_ev_log_crypto_frame_in (const lsquic_cid_t *cid,
1155392f7a3SLiteSpeed Tech                        const struct stream_frame *frame, unsigned enc_level)
1165392f7a3SLiteSpeed Tech{
1175392f7a3SLiteSpeed Tech    LCID("CRYPTO frame in: level %u; offset %"PRIu64"; size %"PRIu16,
1185392f7a3SLiteSpeed Tech        enc_level, frame->data_frame.df_offset, frame->data_frame.df_size);
1195392f7a3SLiteSpeed Tech}
1205392f7a3SLiteSpeed Tech
1215392f7a3SLiteSpeed Tech
1225392f7a3SLiteSpeed Techvoid
1235392f7a3SLiteSpeed Techlsquic_ev_log_stop_waiting_frame_in (const lsquic_cid_t *cid,
1245392f7a3SLiteSpeed Tech                                                        lsquic_packno_t least)
12550aadb33SDmitri Tikhonov{
12650aadb33SDmitri Tikhonov    LCID("STOP_WAITING frame in: least unacked packno %"PRIu64, least);
12750aadb33SDmitri Tikhonov}
12850aadb33SDmitri Tikhonov
12950aadb33SDmitri Tikhonov
13050aadb33SDmitri Tikhonovvoid
1315392f7a3SLiteSpeed Techlsquic_ev_log_window_update_frame_in (const lsquic_cid_t *cid,
1325392f7a3SLiteSpeed Tech                                lsquic_stream_id_t stream_id, uint64_t offset)
13350aadb33SDmitri Tikhonov{
1345392f7a3SLiteSpeed Tech    LCID("WINDOW_UPDATE frame in: stream %"PRIu64"; offset %"PRIu64,
13550aadb33SDmitri Tikhonov        stream_id, offset);
13650aadb33SDmitri Tikhonov}
13750aadb33SDmitri Tikhonov
13850aadb33SDmitri Tikhonov
13950aadb33SDmitri Tikhonovvoid
1405392f7a3SLiteSpeed Techlsquic_ev_log_blocked_frame_in (const lsquic_cid_t *cid,
1415392f7a3SLiteSpeed Tech                                            lsquic_stream_id_t stream_id)
14250aadb33SDmitri Tikhonov{
1435392f7a3SLiteSpeed Tech    LCID("BLOCKED frame in: stream %"PRIu64, stream_id);
14450aadb33SDmitri Tikhonov}
14550aadb33SDmitri Tikhonov
14650aadb33SDmitri Tikhonov
14750aadb33SDmitri Tikhonovvoid
1485392f7a3SLiteSpeed Techlsquic_ev_log_connection_close_frame_in (const lsquic_cid_t *cid,
1495392f7a3SLiteSpeed Tech                    uint64_t error_code, int reason_len, const char *reason)
15050aadb33SDmitri Tikhonov{
1515392f7a3SLiteSpeed Tech    LCID("CONNECTION_CLOSE frame in: error code %"PRIu64", reason: %.*s",
15250aadb33SDmitri Tikhonov        error_code, reason_len, reason);
15350aadb33SDmitri Tikhonov}
15450aadb33SDmitri Tikhonov
15550aadb33SDmitri Tikhonov
15650aadb33SDmitri Tikhonovvoid
1575392f7a3SLiteSpeed Techlsquic_ev_log_goaway_frame_in (const lsquic_cid_t *cid, uint32_t error_code,
1585392f7a3SLiteSpeed Tech            lsquic_stream_id_t stream_id, int reason_len, const char *reason)
15950aadb33SDmitri Tikhonov{
1605392f7a3SLiteSpeed Tech    LCID("GOAWAY frame in: error code %"PRIu32", stream %"PRIu64
16150aadb33SDmitri Tikhonov        ", reason: %.*s", error_code, stream_id, reason_len, reason);
16250aadb33SDmitri Tikhonov}
16350aadb33SDmitri Tikhonov
16450aadb33SDmitri Tikhonov
16550aadb33SDmitri Tikhonovvoid
1665392f7a3SLiteSpeed Techlsquic_ev_log_rst_stream_frame_in (const lsquic_cid_t *cid,
1675392f7a3SLiteSpeed Tech        lsquic_stream_id_t stream_id, uint64_t offset, uint64_t error_code)
16850aadb33SDmitri Tikhonov{
1695392f7a3SLiteSpeed Tech    LCID("RST_STREAM frame in: error code %"PRIu64", stream %"PRIu64
17050aadb33SDmitri Tikhonov        ", offset: %"PRIu64, error_code, stream_id, offset);
17150aadb33SDmitri Tikhonov}
17250aadb33SDmitri Tikhonov
17350aadb33SDmitri Tikhonov
17450aadb33SDmitri Tikhonovvoid
1755392f7a3SLiteSpeed Techlsquic_ev_log_stop_sending_frame_in (const lsquic_cid_t *cid,
1765392f7a3SLiteSpeed Tech                        lsquic_stream_id_t stream_id, uint64_t error_code)
1775392f7a3SLiteSpeed Tech{
1785392f7a3SLiteSpeed Tech    LCID("STOP_SENDING frame in: error code %"PRIu64", stream %"PRIu64,
1795392f7a3SLiteSpeed Tech                                                     error_code, stream_id);
1805392f7a3SLiteSpeed Tech}
1815392f7a3SLiteSpeed Tech
1825392f7a3SLiteSpeed Tech
1835392f7a3SLiteSpeed Techvoid
1845392f7a3SLiteSpeed Techlsquic_ev_log_padding_frame_in (const lsquic_cid_t *cid, size_t len)
18550aadb33SDmitri Tikhonov{
18650aadb33SDmitri Tikhonov    LCID("PADDING frame in of %zd bytes", len);
18750aadb33SDmitri Tikhonov}
18850aadb33SDmitri Tikhonov
18950aadb33SDmitri Tikhonov
19050aadb33SDmitri Tikhonovvoid
1915392f7a3SLiteSpeed Techlsquic_ev_log_ping_frame_in (const lsquic_cid_t *cid)
19250aadb33SDmitri Tikhonov{
19350aadb33SDmitri Tikhonov    LCID("PING frame in");
19450aadb33SDmitri Tikhonov}
19550aadb33SDmitri Tikhonov
19650aadb33SDmitri Tikhonov
19750aadb33SDmitri Tikhonovvoid
1985392f7a3SLiteSpeed Techlsquic_ev_log_packet_created (const lsquic_cid_t *cid,
19950aadb33SDmitri Tikhonov                                const struct lsquic_packet_out *packet_out)
20050aadb33SDmitri Tikhonov{
20150aadb33SDmitri Tikhonov    LCID("created packet %"PRIu64"; flags: version=%d, nonce=%d, conn_id=%d",
20250aadb33SDmitri Tikhonov        packet_out->po_packno,
20350aadb33SDmitri Tikhonov        !!(packet_out->po_flags & PO_VERSION),
20450aadb33SDmitri Tikhonov        !!(packet_out->po_flags & PO_NONCE),
20550aadb33SDmitri Tikhonov        !!(packet_out->po_flags & PO_CONN_ID));
20650aadb33SDmitri Tikhonov}
20750aadb33SDmitri Tikhonov
20850aadb33SDmitri Tikhonov
20950aadb33SDmitri Tikhonovvoid
2105392f7a3SLiteSpeed Techlsquic_ev_log_packet_sent (const lsquic_cid_t *cid,
21150aadb33SDmitri Tikhonov                                const struct lsquic_packet_out *packet_out)
21250aadb33SDmitri Tikhonov{
21350aadb33SDmitri Tikhonov    char frames[lsquic_frame_types_str_sz];
21450aadb33SDmitri Tikhonov    if (lsquic_packet_out_verneg(packet_out))
21550aadb33SDmitri Tikhonov        LCID("sent version negotiation packet, size %hu",
21650aadb33SDmitri Tikhonov                                                    packet_out->po_data_sz);
2175392f7a3SLiteSpeed Tech    else if (lsquic_packet_out_retry(packet_out))
2185392f7a3SLiteSpeed Tech        LCID("sent stateless retry packet, size %hu", packet_out->po_data_sz);
21950aadb33SDmitri Tikhonov    else if (lsquic_packet_out_pubres(packet_out))
22050aadb33SDmitri Tikhonov        LCID("sent public reset packet, size %hu", packet_out->po_data_sz);
2215392f7a3SLiteSpeed Tech    else if (packet_out->po_lflags & POL_GQUIC)
22250aadb33SDmitri Tikhonov        LCID("sent packet %"PRIu64", size %hu, frame types: %s",
22350aadb33SDmitri Tikhonov            packet_out->po_packno, packet_out->po_enc_data_sz,
22450aadb33SDmitri Tikhonov                /* Frame types is a list of different frames types contained
22550aadb33SDmitri Tikhonov                 * in the packet, no more.  Count and order of frames is not
22650aadb33SDmitri Tikhonov                 * printed.
22750aadb33SDmitri Tikhonov                 */
22850aadb33SDmitri Tikhonov                lsquic_frame_types_to_str(frames, sizeof(frames),
22950aadb33SDmitri Tikhonov                                                packet_out->po_frame_types));
23002b6086dSDmitri Tikhonov    else if (packet_out->po_lflags & POL_LOG_QL_BITS)
23102b6086dSDmitri Tikhonov        LCID("sent packet %"PRIu64", type %s, crypto: %s, size %hu, frame "
23202b6086dSDmitri Tikhonov            "types: %s, ecn: %u, spin: %d; kp: %u, path: %hhu, flags: %u; "
23302b6086dSDmitri Tikhonov            "Q: %u; L: %u",
23402b6086dSDmitri Tikhonov            packet_out->po_packno, lsquic_hety2str[packet_out->po_header_type],
23502b6086dSDmitri Tikhonov            lsquic_enclev2str[ lsquic_packet_out_enc_level(packet_out) ],
23602b6086dSDmitri Tikhonov            packet_out->po_enc_data_sz,
23702b6086dSDmitri Tikhonov                /* Frame types is a list of different frames types contained
23802b6086dSDmitri Tikhonov                 * in the packet, no more.  Count and order of frames is not
23902b6086dSDmitri Tikhonov                 * printed.
24002b6086dSDmitri Tikhonov                 */
24102b6086dSDmitri Tikhonov                lsquic_frame_types_to_str(frames, sizeof(frames),
24202b6086dSDmitri Tikhonov                                                packet_out->po_frame_types),
24302b6086dSDmitri Tikhonov                lsquic_packet_out_ecn(packet_out),
24402b6086dSDmitri Tikhonov                /* spin bit value is only valid for short packet headers */
24502b6086dSDmitri Tikhonov                lsquic_packet_out_spin_bit(packet_out),
24602b6086dSDmitri Tikhonov                lsquic_packet_out_kp(packet_out),
24702b6086dSDmitri Tikhonov                packet_out->po_path->np_path_id,
24802b6086dSDmitri Tikhonov                (unsigned) packet_out->po_flags,
24902b6086dSDmitri Tikhonov                lsquic_packet_out_square_bit(packet_out),
25002b6086dSDmitri Tikhonov                lsquic_packet_out_loss_bit(packet_out));
2519626cfc2SDmitri Tikhonov    else
2529626cfc2SDmitri Tikhonov        LCID("sent packet %"PRIu64", type %s, crypto: %s, size %hu, frame "
25384dbbb75SDmitri Tikhonov            "types: %s, ecn: %u, spin: %d; kp: %u, path: %hhu, flags: %u",
2549626cfc2SDmitri Tikhonov            packet_out->po_packno, lsquic_hety2str[packet_out->po_header_type],
2559626cfc2SDmitri Tikhonov            lsquic_enclev2str[ lsquic_packet_out_enc_level(packet_out) ],
2569626cfc2SDmitri Tikhonov            packet_out->po_enc_data_sz,
2579626cfc2SDmitri Tikhonov                /* Frame types is a list of different frames types contained
2589626cfc2SDmitri Tikhonov                 * in the packet, no more.  Count and order of frames is not
2599626cfc2SDmitri Tikhonov                 * printed.
2609626cfc2SDmitri Tikhonov                 */
2619626cfc2SDmitri Tikhonov                lsquic_frame_types_to_str(frames, sizeof(frames),
2625392f7a3SLiteSpeed Tech                                                packet_out->po_frame_types),
2635392f7a3SLiteSpeed Tech                lsquic_packet_out_ecn(packet_out),
2645392f7a3SLiteSpeed Tech                /* spin bit value is only valid for short packet headers */
2655392f7a3SLiteSpeed Tech                lsquic_packet_out_spin_bit(packet_out),
2665392f7a3SLiteSpeed Tech                lsquic_packet_out_kp(packet_out),
26784dbbb75SDmitri Tikhonov                packet_out->po_path->np_path_id,
26884dbbb75SDmitri Tikhonov                (unsigned) packet_out->po_flags);
26950aadb33SDmitri Tikhonov}
27050aadb33SDmitri Tikhonov
27150aadb33SDmitri Tikhonov
27250aadb33SDmitri Tikhonovvoid
2735392f7a3SLiteSpeed Techlsquic_ev_log_packet_not_sent (const lsquic_cid_t *cid,
27450aadb33SDmitri Tikhonov                                const struct lsquic_packet_out *packet_out)
27550aadb33SDmitri Tikhonov{
27650aadb33SDmitri Tikhonov    char frames[lsquic_frame_types_str_sz];
27750aadb33SDmitri Tikhonov    LCID("unsent packet %"PRIu64", size %hu, frame types: %s",
27850aadb33SDmitri Tikhonov        packet_out->po_packno, packet_out->po_enc_data_sz,
27950aadb33SDmitri Tikhonov            /* Frame types is a list of different frames types contained in
28050aadb33SDmitri Tikhonov             * the packet, no more.  Count and order of frames is not printed.
28150aadb33SDmitri Tikhonov             */
28250aadb33SDmitri Tikhonov            lsquic_frame_types_to_str(frames, sizeof(frames),
28350aadb33SDmitri Tikhonov                                                packet_out->po_frame_types));
28450aadb33SDmitri Tikhonov}
28550aadb33SDmitri Tikhonov
28650aadb33SDmitri Tikhonov
28750aadb33SDmitri Tikhonovvoid
2885392f7a3SLiteSpeed Techlsquic_ev_log_http_headers_in (const lsquic_cid_t *cid, int is_server,
28950aadb33SDmitri Tikhonov                                        const struct uncompressed_headers *uh)
29050aadb33SDmitri Tikhonov{
2913b55e6aeSDmitri Tikhonov    const struct http1x_headers *h1h;
29250aadb33SDmitri Tikhonov    const char *cr, *p;
29350aadb33SDmitri Tikhonov
29450aadb33SDmitri Tikhonov    if (uh->uh_flags & UH_PP)
2955392f7a3SLiteSpeed Tech        LCID("read push promise; stream %"PRIu64", promised stream %"PRIu64,
29650aadb33SDmitri Tikhonov            uh->uh_stream_id, uh->uh_oth_stream_id);
29750aadb33SDmitri Tikhonov    else
2985392f7a3SLiteSpeed Tech        LCID("read %s headers; stream: %"PRIu64", depends on stream: %"PRIu64
29950aadb33SDmitri Tikhonov            ", weight: %hu, exclusive: %d, fin: %d",
30050aadb33SDmitri Tikhonov            is_server ? "request" : "response",
30150aadb33SDmitri Tikhonov            uh->uh_stream_id, uh->uh_oth_stream_id, uh->uh_weight,
30250aadb33SDmitri Tikhonov            (int) uh->uh_exclusive, !!(uh->uh_flags & UH_FIN));
30350aadb33SDmitri Tikhonov
3043b55e6aeSDmitri Tikhonov    if (uh->uh_flags & UH_H1H)
30550aadb33SDmitri Tikhonov    {
3063b55e6aeSDmitri Tikhonov        h1h = uh->uh_hset;
3073b55e6aeSDmitri Tikhonov        for (p = h1h->h1h_buf; p < h1h->h1h_buf + h1h->h1h_size; p = cr + 2)
3083b55e6aeSDmitri Tikhonov        {
3093b55e6aeSDmitri Tikhonov            cr = strchr(p, '\r');
3103b55e6aeSDmitri Tikhonov            if (cr && cr > p)
3113b55e6aeSDmitri Tikhonov                LCID("  %.*s", (int) (cr - p), p);
3123b55e6aeSDmitri Tikhonov            else
3133b55e6aeSDmitri Tikhonov                break;
3143b55e6aeSDmitri Tikhonov        }
31550aadb33SDmitri Tikhonov    }
31650aadb33SDmitri Tikhonov}
31750aadb33SDmitri Tikhonov
31850aadb33SDmitri Tikhonov
31950aadb33SDmitri Tikhonovvoid
3205392f7a3SLiteSpeed Techlsquic_ev_log_action_stream_frame (const lsquic_cid_t *cid,
321c51ce338SDmitri Tikhonov    const struct parse_funcs *pf, const unsigned char *buf, size_t bufsz,
322c51ce338SDmitri Tikhonov    const char *what)
32350aadb33SDmitri Tikhonov{
32450aadb33SDmitri Tikhonov    struct stream_frame frame;
32550aadb33SDmitri Tikhonov    int len;
32650aadb33SDmitri Tikhonov
32750aadb33SDmitri Tikhonov    len = pf->pf_parse_stream_frame(buf, bufsz, &frame);
32850aadb33SDmitri Tikhonov    if (len > 0)
3295392f7a3SLiteSpeed Tech        LCID("%s STREAM frame: stream %"PRIu64", offset: %"PRIu64
330c51ce338SDmitri Tikhonov            ", size: %"PRIu16", fin: %d", what, frame.stream_id,
33150aadb33SDmitri Tikhonov            frame.data_frame.df_offset, frame.data_frame.df_size,
33250aadb33SDmitri Tikhonov            frame.data_frame.df_fin);
33350aadb33SDmitri Tikhonov    else
33450aadb33SDmitri Tikhonov        LSQ_LOG2(LSQ_LOG_WARN, "cannot parse STREAM frame");
33550aadb33SDmitri Tikhonov}
33650aadb33SDmitri Tikhonov
33750aadb33SDmitri Tikhonov
33850aadb33SDmitri Tikhonovvoid
3395392f7a3SLiteSpeed Techlsquic_ev_log_generated_crypto_frame (const lsquic_cid_t *cid,
3405392f7a3SLiteSpeed Tech       const struct parse_funcs *pf, const unsigned char *buf, size_t bufsz)
3415392f7a3SLiteSpeed Tech{
3425392f7a3SLiteSpeed Tech    struct stream_frame frame;
3435392f7a3SLiteSpeed Tech    int len;
3445392f7a3SLiteSpeed Tech
3455392f7a3SLiteSpeed Tech    len = pf->pf_parse_crypto_frame(buf, bufsz, &frame);
3465392f7a3SLiteSpeed Tech    if (len > 0)
3475392f7a3SLiteSpeed Tech        LCID("generated CRYPTO frame: offset: %"PRIu64", size: %"PRIu16,
3485392f7a3SLiteSpeed Tech            frame.data_frame.df_offset, frame.data_frame.df_size);
3495392f7a3SLiteSpeed Tech    else
3505392f7a3SLiteSpeed Tech        LSQ_LOG2(LSQ_LOG_WARN, "cannot parse CRYPTO frame");
3515392f7a3SLiteSpeed Tech}
3525392f7a3SLiteSpeed Tech
3535392f7a3SLiteSpeed Tech
3545392f7a3SLiteSpeed Techvoid
3555392f7a3SLiteSpeed Techlsquic_ev_log_generated_ack_frame (const lsquic_cid_t *cid,
3565392f7a3SLiteSpeed Tech                const struct parse_funcs *pf, const unsigned char *ack_buf,
3575392f7a3SLiteSpeed Tech                size_t ack_buf_sz)
35850aadb33SDmitri Tikhonov{
35950aadb33SDmitri Tikhonov    struct ack_info acki;
36050aadb33SDmitri Tikhonov    int len;
361de46bf2fSDmitri Tikhonov    char buf[MAX_ACKI_STR_SZ];
36250aadb33SDmitri Tikhonov
3635392f7a3SLiteSpeed Tech    len = pf->pf_parse_ack_frame(ack_buf, ack_buf_sz, &acki,
3645392f7a3SLiteSpeed Tech                                                    TP_DEF_ACK_DELAY_EXP);
36550aadb33SDmitri Tikhonov    if (len < 0)
36650aadb33SDmitri Tikhonov    {
36750aadb33SDmitri Tikhonov        LSQ_LOG2(LSQ_LOG_WARN, "cannot parse ACK frame");
36850aadb33SDmitri Tikhonov        return;
36950aadb33SDmitri Tikhonov    }
37050aadb33SDmitri Tikhonov
371de46bf2fSDmitri Tikhonov    lsquic_acki2str(&acki, buf, sizeof(buf));
372de46bf2fSDmitri Tikhonov    LCID("generated ACK frame: %s", buf);
37350aadb33SDmitri Tikhonov}
37450aadb33SDmitri Tikhonov
37550aadb33SDmitri Tikhonov
37650aadb33SDmitri Tikhonovvoid
3775392f7a3SLiteSpeed Techlsquic_ev_log_generated_new_token_frame (const lsquic_cid_t *cid,
3785392f7a3SLiteSpeed Tech                const struct parse_funcs *pf, const unsigned char *frame_buf,
3795392f7a3SLiteSpeed Tech                size_t frame_buf_sz)
3805392f7a3SLiteSpeed Tech{
3815392f7a3SLiteSpeed Tech    const unsigned char *token;
3825392f7a3SLiteSpeed Tech    size_t sz;
3835392f7a3SLiteSpeed Tech    char *buf;
3845392f7a3SLiteSpeed Tech    int len;
3855392f7a3SLiteSpeed Tech
3865392f7a3SLiteSpeed Tech    len = pf->pf_parse_new_token_frame(frame_buf, frame_buf_sz, &token, &sz);
3875392f7a3SLiteSpeed Tech    if (len < 0)
3885392f7a3SLiteSpeed Tech    {
3895392f7a3SLiteSpeed Tech        LSQ_LOG2(LSQ_LOG_WARN, "cannot parse NEW_TOKEN frame");
3905392f7a3SLiteSpeed Tech        return;
3915392f7a3SLiteSpeed Tech    }
3925392f7a3SLiteSpeed Tech
3935392f7a3SLiteSpeed Tech    buf = malloc(sz * 2 + 1);
3945392f7a3SLiteSpeed Tech    if (buf)
3955392f7a3SLiteSpeed Tech    {
3965392f7a3SLiteSpeed Tech        lsquic_hexstr(token, sz, buf, sz * 2 + 1);
3975392f7a3SLiteSpeed Tech        LCID("generated NEW_TOKEN frame: %s", buf);
3985392f7a3SLiteSpeed Tech        free(buf);
3995392f7a3SLiteSpeed Tech    }
4005392f7a3SLiteSpeed Tech}
4015392f7a3SLiteSpeed Tech
4025392f7a3SLiteSpeed Tech
4035392f7a3SLiteSpeed Techvoid
4045392f7a3SLiteSpeed Techlsquic_ev_log_generated_path_chal_frame (const lsquic_cid_t *cid,
4055392f7a3SLiteSpeed Tech                const struct parse_funcs *pf, const unsigned char *frame_buf,
4065392f7a3SLiteSpeed Tech                size_t frame_buf_sz)
4075392f7a3SLiteSpeed Tech{
4085392f7a3SLiteSpeed Tech    uint64_t chal;
4095392f7a3SLiteSpeed Tech    int len;
4105392f7a3SLiteSpeed Tech    char hexbuf[sizeof(chal) * 2 + 1];
4115392f7a3SLiteSpeed Tech
4125392f7a3SLiteSpeed Tech    len = pf->pf_parse_path_chal_frame(frame_buf, frame_buf_sz, &chal);
4135392f7a3SLiteSpeed Tech    if (len > 0)
4145392f7a3SLiteSpeed Tech        LCID("generated PATH_CHALLENGE(%s) frame",
4155392f7a3SLiteSpeed Tech                        HEXSTR((unsigned char *) &chal, sizeof(chal), hexbuf));
4165392f7a3SLiteSpeed Tech    else
4175392f7a3SLiteSpeed Tech        LSQ_LOG2(LSQ_LOG_WARN, "cannot parse PATH_CHALLENGE frame");
4185392f7a3SLiteSpeed Tech}
4195392f7a3SLiteSpeed Tech
4205392f7a3SLiteSpeed Tech
4215392f7a3SLiteSpeed Techvoid
4225392f7a3SLiteSpeed Techlsquic_ev_log_generated_path_resp_frame (const lsquic_cid_t *cid,
4235392f7a3SLiteSpeed Tech                const struct parse_funcs *pf, const unsigned char *frame_buf,
4245392f7a3SLiteSpeed Tech                size_t frame_buf_sz)
4255392f7a3SLiteSpeed Tech{
4265392f7a3SLiteSpeed Tech    uint64_t resp;
4275392f7a3SLiteSpeed Tech    int len;
4285392f7a3SLiteSpeed Tech    char hexbuf[sizeof(resp) * 2 + 1];
4295392f7a3SLiteSpeed Tech
4305392f7a3SLiteSpeed Tech    len = pf->pf_parse_path_resp_frame(frame_buf, frame_buf_sz, &resp);
4315392f7a3SLiteSpeed Tech    if (len > 0)
4325392f7a3SLiteSpeed Tech        LCID("generated PATH_RESPONSE(%s) frame",
4335392f7a3SLiteSpeed Tech                        HEXSTR((unsigned char *) &resp, sizeof(resp), hexbuf));
4345392f7a3SLiteSpeed Tech    else
4355392f7a3SLiteSpeed Tech        LSQ_LOG2(LSQ_LOG_WARN, "cannot parse PATH_RESPONSE frame");
4365392f7a3SLiteSpeed Tech}
4375392f7a3SLiteSpeed Tech
4385392f7a3SLiteSpeed Tech
4395392f7a3SLiteSpeed Techvoid
4405392f7a3SLiteSpeed Techlsquic_ev_log_generated_new_connection_id_frame (const lsquic_cid_t *cid,
4415392f7a3SLiteSpeed Tech                const struct parse_funcs *pf, const unsigned char *frame_buf,
4425392f7a3SLiteSpeed Tech                size_t frame_buf_sz)
4435392f7a3SLiteSpeed Tech{
4445392f7a3SLiteSpeed Tech    const unsigned char *token;
4455392f7a3SLiteSpeed Tech    lsquic_cid_t new_cid;
4465392f7a3SLiteSpeed Tech    uint64_t seqno, retire_prior_to;
4475392f7a3SLiteSpeed Tech    int len;
4485392f7a3SLiteSpeed Tech    char token_buf[IQUIC_SRESET_TOKEN_SZ * 2 + 1];
4495392f7a3SLiteSpeed Tech    char cid_buf[MAX_CID_LEN * 2 + 1];
4505392f7a3SLiteSpeed Tech
4515392f7a3SLiteSpeed Tech    len = pf->pf_parse_new_conn_id(frame_buf, frame_buf_sz, &seqno,
4525392f7a3SLiteSpeed Tech                                        &retire_prior_to, &new_cid, &token);
4535392f7a3SLiteSpeed Tech    if (len < 0)
4545392f7a3SLiteSpeed Tech    {
4555392f7a3SLiteSpeed Tech        LSQ_LOG2(LSQ_LOG_WARN, "cannot parse NEW_CONNECTION_ID frame");
4565392f7a3SLiteSpeed Tech        return;
4575392f7a3SLiteSpeed Tech    }
4585392f7a3SLiteSpeed Tech
4595392f7a3SLiteSpeed Tech    lsquic_hexstr(new_cid.idbuf, new_cid.len, cid_buf, sizeof(cid_buf));
4605392f7a3SLiteSpeed Tech    lsquic_hexstr(token, IQUIC_SRESET_TOKEN_SZ, token_buf, sizeof(token_buf));
4615392f7a3SLiteSpeed Tech    LCID("generated NEW_CONNECTION_ID frame: seqno: %"PRIu64"; retire prior "
4625392f7a3SLiteSpeed Tech        "to: %"PRIu64"; cid: %s; token: %s", seqno, retire_prior_to,
4635392f7a3SLiteSpeed Tech        cid_buf, token_buf);
4645392f7a3SLiteSpeed Tech}
4655392f7a3SLiteSpeed Tech
4665392f7a3SLiteSpeed Tech
4675392f7a3SLiteSpeed Techvoid
4685392f7a3SLiteSpeed Techlsquic_ev_log_generated_stop_waiting_frame (const lsquic_cid_t *cid,
46950aadb33SDmitri Tikhonov                                            lsquic_packno_t lunack)
47050aadb33SDmitri Tikhonov{
47150aadb33SDmitri Tikhonov    LCID("generated STOP_WAITING frame; least unacked: %"PRIu64, lunack);
47250aadb33SDmitri Tikhonov}
47350aadb33SDmitri Tikhonov
47450aadb33SDmitri Tikhonov
47550aadb33SDmitri Tikhonovvoid
4765392f7a3SLiteSpeed Techlsquic_ev_log_generated_stop_sending_frame (const lsquic_cid_t *cid,
4775392f7a3SLiteSpeed Tech                            lsquic_stream_id_t stream_id, uint16_t error_code)
4785392f7a3SLiteSpeed Tech{
4795392f7a3SLiteSpeed Tech    LCID("generated STOP_SENDING frame; stream ID: %"PRIu64"; error code: "
4805392f7a3SLiteSpeed Tech                                            "%"PRIu16, stream_id, error_code);
4815392f7a3SLiteSpeed Tech}
4825392f7a3SLiteSpeed Tech
4835392f7a3SLiteSpeed Tech
4845392f7a3SLiteSpeed Techvoid
4855392f7a3SLiteSpeed Techlsquic_ev_log_generated_http_headers (const lsquic_cid_t *cid,
4865392f7a3SLiteSpeed Tech                    lsquic_stream_id_t stream_id,
48750aadb33SDmitri Tikhonov                    int is_server, const struct http_prio_frame *prio_frame,
48850aadb33SDmitri Tikhonov                    const struct lsquic_http_headers *headers)
48950aadb33SDmitri Tikhonov{
4905392f7a3SLiteSpeed Tech    lsquic_stream_id_t dep_stream_id;
49150aadb33SDmitri Tikhonov    int exclusive, i;
49250aadb33SDmitri Tikhonov    unsigned short weight;
49350aadb33SDmitri Tikhonov
49450aadb33SDmitri Tikhonov    if (is_server)
4955392f7a3SLiteSpeed Tech        LCID("generated HTTP response HEADERS for stream %"PRIu64, stream_id);
49650aadb33SDmitri Tikhonov    else
49750aadb33SDmitri Tikhonov    {
49850aadb33SDmitri Tikhonov        memcpy(&dep_stream_id, prio_frame->hpf_stream_id, 4);
49950aadb33SDmitri Tikhonov        dep_stream_id = htonl(dep_stream_id);
50050aadb33SDmitri Tikhonov        exclusive = dep_stream_id >> 31;
50150aadb33SDmitri Tikhonov        dep_stream_id &= ~(1 << 31);
50250aadb33SDmitri Tikhonov        weight = prio_frame->hpf_weight + 1;
5035392f7a3SLiteSpeed Tech        LCID("generated HTTP request HEADERS for stream %"PRIu64
5045392f7a3SLiteSpeed Tech            ", dep stream: %"PRIu64", weight: %hu, exclusive: %d", stream_id,
50550aadb33SDmitri Tikhonov            dep_stream_id, weight, exclusive);
50650aadb33SDmitri Tikhonov    }
50750aadb33SDmitri Tikhonov
50850aadb33SDmitri Tikhonov    for (i = 0; i < headers->count; ++i)
50950aadb33SDmitri Tikhonov        LCID("  %.*s: %.*s",
51050aadb33SDmitri Tikhonov            (int)    headers->headers[i].name.iov_len,
51150aadb33SDmitri Tikhonov            (char *) headers->headers[i].name.iov_base,
51250aadb33SDmitri Tikhonov            (int)    headers->headers[i].value.iov_len,
51350aadb33SDmitri Tikhonov            (char *) headers->headers[i].value.iov_base);
51450aadb33SDmitri Tikhonov}
51550aadb33SDmitri Tikhonov
51650aadb33SDmitri Tikhonov
51750aadb33SDmitri Tikhonovvoid
5185392f7a3SLiteSpeed Techlsquic_ev_log_generated_http_push_promise (const lsquic_cid_t *cid,
5195392f7a3SLiteSpeed Tech            lsquic_stream_id_t stream_id, lsquic_stream_id_t promised_stream_id,
5205392f7a3SLiteSpeed Tech            const struct lsquic_http_headers *headers,
5215392f7a3SLiteSpeed Tech            const struct lsquic_http_headers *extra_headers)
52250aadb33SDmitri Tikhonov{
52350aadb33SDmitri Tikhonov    int i;
52450aadb33SDmitri Tikhonov
5255392f7a3SLiteSpeed Tech    LCID("generated HTTP PUSH_PROMISE for stream %"PRIu64"; promised stream %"
5265392f7a3SLiteSpeed Tech        PRIu64, stream_id, promised_stream_id);
52750aadb33SDmitri Tikhonov
52850aadb33SDmitri Tikhonov    for (i = 0; i < headers->count; ++i)
52950aadb33SDmitri Tikhonov        LCID("  %.*s: %.*s",
53050aadb33SDmitri Tikhonov            (int)    headers->headers[i].name.iov_len,
53150aadb33SDmitri Tikhonov            (char *) headers->headers[i].name.iov_base,
53250aadb33SDmitri Tikhonov            (int)    headers->headers[i].value.iov_len,
53350aadb33SDmitri Tikhonov            (char *) headers->headers[i].value.iov_base);
53450aadb33SDmitri Tikhonov
53550aadb33SDmitri Tikhonov    if (extra_headers)
53650aadb33SDmitri Tikhonov        for (i = 0; i < extra_headers->count; ++i)
53750aadb33SDmitri Tikhonov            LCID("  %.*s: %.*s",
53850aadb33SDmitri Tikhonov                (int)    extra_headers->headers[i].name.iov_len,
53950aadb33SDmitri Tikhonov                (char *) extra_headers->headers[i].name.iov_base,
54050aadb33SDmitri Tikhonov                (int)    extra_headers->headers[i].value.iov_len,
54150aadb33SDmitri Tikhonov                (char *) extra_headers->headers[i].value.iov_base);
54250aadb33SDmitri Tikhonov}
54355cd0b38SDmitri Tikhonov
54455cd0b38SDmitri Tikhonovvoid
5455392f7a3SLiteSpeed Techlsquic_ev_log_create_connection (const lsquic_cid_t *cid,
54655cd0b38SDmitri Tikhonov                                    const struct sockaddr *local_sa,
54755cd0b38SDmitri Tikhonov                                    const struct sockaddr *peer_sa)
54855cd0b38SDmitri Tikhonov{
54955cd0b38SDmitri Tikhonov    LCID("connection created");
55055cd0b38SDmitri Tikhonov}
55155cd0b38SDmitri Tikhonov
55255cd0b38SDmitri Tikhonov
55355cd0b38SDmitri Tikhonovvoid
5545392f7a3SLiteSpeed Techlsquic_ev_log_hsk_completed (const lsquic_cid_t *cid)
55555cd0b38SDmitri Tikhonov{
55655cd0b38SDmitri Tikhonov    LCID("handshake completed");
55755cd0b38SDmitri Tikhonov}
55855cd0b38SDmitri Tikhonov
55955cd0b38SDmitri Tikhonov
56055cd0b38SDmitri Tikhonovvoid
5615392f7a3SLiteSpeed Techlsquic_ev_log_zero_rtt (const lsquic_cid_t *cid)
56255cd0b38SDmitri Tikhonov{
56355cd0b38SDmitri Tikhonov    LCID("zero_rtt successful");
56455cd0b38SDmitri Tikhonov}
56555cd0b38SDmitri Tikhonov
56655cd0b38SDmitri Tikhonov
56755cd0b38SDmitri Tikhonovvoid
5685392f7a3SLiteSpeed Techlsquic_ev_log_check_certs (const lsquic_cid_t *cid, const lsquic_str_t **certs,
56955cd0b38SDmitri Tikhonov                                                                size_t count)
57055cd0b38SDmitri Tikhonov{
57155cd0b38SDmitri Tikhonov    LCID("check certs");
57255cd0b38SDmitri Tikhonov}
57355cd0b38SDmitri Tikhonov
57455cd0b38SDmitri Tikhonov
57555cd0b38SDmitri Tikhonovvoid
5765392f7a3SLiteSpeed Techlsquic_ev_log_version_negotiation (const lsquic_cid_t *cid,
57755cd0b38SDmitri Tikhonov                                        const char *action, const char *ver)
57855cd0b38SDmitri Tikhonov{
57955cd0b38SDmitri Tikhonov    LCID("version negotiation: %s version %s", action, ver);
58055cd0b38SDmitri Tikhonov}
581