diff options
Diffstat (limited to '')
-rw-r--r-- | lib/ngtcp2_log.c | 821 |
1 files changed, 821 insertions, 0 deletions
diff --git a/lib/ngtcp2_log.c b/lib/ngtcp2_log.c new file mode 100644 index 0000000..28f3c93 --- /dev/null +++ b/lib/ngtcp2_log.c @@ -0,0 +1,821 @@ +/* + * ngtcp2 + * + * Copyright (c) 2018 ngtcp2 contributors + * + * Permission is hereby granted, free of charge, to any person obtaining + * a copy of this software and associated documentation files (the + * "Software"), to deal in the Software without restriction, including + * without limitation the rights to use, copy, modify, merge, publish, + * distribute, sublicense, and/or sell copies of the Software, and to + * permit persons to whom the Software is furnished to do so, subject to + * the following conditions: + * + * The above copyright notice and this permission notice shall be + * included in all copies or substantial portions of the Software. + * + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, + * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF + * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND + * NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE + * LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION + * OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION + * WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. + */ +#include "ngtcp2_log.h" + +#include <stdio.h> +#ifdef HAVE_UNISTD_H +# include <unistd.h> +#endif +#include <assert.h> +#include <string.h> + +#include "ngtcp2_str.h" +#include "ngtcp2_vec.h" +#include "ngtcp2_macro.h" +#include "ngtcp2_conv.h" +#include "ngtcp2_unreachable.h" +#include "ngtcp2_net.h" + +void ngtcp2_log_init(ngtcp2_log *log, const ngtcp2_cid *scid, + ngtcp2_printf log_printf, ngtcp2_tstamp ts, + void *user_data) { + if (scid) { + ngtcp2_encode_hex(log->scid, scid->data, scid->datalen); + } else { + log->scid[0] = '\0'; + } + log->log_printf = log_printf; + log->ts = log->last_ts = ts; + log->user_data = user_data; +} + +/* + * # Log header + * + * <LEVEL><TIMESTAMP> <SCID> <EVENT> + * + * <LEVEL>: + * Log level. I=Info, W=Warning, E=Error + * + * <TIMESTAMP>: + * Timestamp relative to ngtcp2_log.ts field in milliseconds + * resolution. + * + * <SCID>: + * Source Connection ID in hex string. + * + * <EVENT>: + * Event. pkt=packet, frm=frame, rcv=recovery, cry=crypto, + * con=connection(catch all) + * + * # Frame event + * + * <DIR> <PKN> <PKTNAME> <FRAMENAME>(<FRAMETYPE>) + * + * <DIR>: + * Flow direction. tx=transmission, rx=reception + * + * <PKN>: + * Packet number. + * + * <PKTNAME>: + * Packet name. (e.g., Initial, Handshake, 1RTT) + * + * <FRAMENAME>: + * Frame name. (e.g., STREAM, ACK, PING) + * + * <FRAMETYPE>: + * Frame type in hex string. + */ + +#define NGTCP2_LOG_BUFLEN 4096 + +/* TODO Split second and remaining fraction with comma */ +#define NGTCP2_LOG_HD "I%08" PRIu64 " 0x%s %s" +#define NGTCP2_LOG_PKT NGTCP2_LOG_HD " %s %" PRId64 " %s" +#define NGTCP2_LOG_TP NGTCP2_LOG_HD " remote transport_parameters" + +#define NGTCP2_LOG_FRM_HD_FIELDS(DIR) \ + timestamp_cast(log->last_ts - log->ts), (const char *)log->scid, "frm", \ + (DIR), hd->pkt_num, strpkttype(hd) + +#define NGTCP2_LOG_PKT_HD_FIELDS(DIR) \ + timestamp_cast(log->last_ts - log->ts), (const char *)log->scid, "pkt", \ + (DIR), hd->pkt_num, strpkttype(hd) + +#define NGTCP2_LOG_TP_HD_FIELDS \ + timestamp_cast(log->last_ts - log->ts), (const char *)log->scid, "cry" + +static const char *strerrorcode(uint64_t error_code) { + switch (error_code) { + case NGTCP2_NO_ERROR: + return "NO_ERROR"; + case NGTCP2_INTERNAL_ERROR: + return "INTERNAL_ERROR"; + case NGTCP2_CONNECTION_REFUSED: + return "CONNECTION_REFUSED"; + case NGTCP2_FLOW_CONTROL_ERROR: + return "FLOW_CONTROL_ERROR"; + case NGTCP2_STREAM_LIMIT_ERROR: + return "STREAM_LIMIT_ERROR"; + case NGTCP2_STREAM_STATE_ERROR: + return "STREAM_STATE_ERROR"; + case NGTCP2_FINAL_SIZE_ERROR: + return "FINAL_SIZE_ERROR"; + case NGTCP2_FRAME_ENCODING_ERROR: + return "FRAME_ENCODING_ERROR"; + case NGTCP2_TRANSPORT_PARAMETER_ERROR: + return "TRANSPORT_PARAMETER_ERROR"; + case NGTCP2_CONNECTION_ID_LIMIT_ERROR: + return "CONNECTION_ID_LIMIT_ERROR"; + case NGTCP2_PROTOCOL_VIOLATION: + return "PROTOCOL_VIOLATION"; + case NGTCP2_INVALID_TOKEN: + return "INVALID_TOKEN"; + case NGTCP2_APPLICATION_ERROR: + return "APPLICATION_ERROR"; + case NGTCP2_CRYPTO_BUFFER_EXCEEDED: + return "CRYPTO_BUFFER_EXCEEDED"; + case NGTCP2_KEY_UPDATE_ERROR: + return "KEY_UPDATE_ERROR"; + case NGTCP2_VERSION_NEGOTIATION_ERROR_DRAFT: + return "VERSION_NEGOTIATION_ERROR"; + default: + if (0x100u <= error_code && error_code <= 0x1ffu) { + return "CRYPTO_ERROR"; + } + return "(unknown)"; + } +} + +static const char *strapperrorcode(uint64_t app_error_code) { + (void)app_error_code; + return "(unknown)"; +} + +static const char *strpkttype_long(uint8_t type) { + switch (type) { + case NGTCP2_PKT_INITIAL: + return "Initial"; + case NGTCP2_PKT_RETRY: + return "Retry"; + case NGTCP2_PKT_HANDSHAKE: + return "Handshake"; + case NGTCP2_PKT_0RTT: + return "0RTT"; + default: + return "(unknown)"; + } +} + +static const char *strpkttype(const ngtcp2_pkt_hd *hd) { + if (hd->flags & NGTCP2_PKT_FLAG_LONG_FORM) { + return strpkttype_long(hd->type); + } + + switch (hd->type) { + case NGTCP2_PKT_VERSION_NEGOTIATION: + return "VN"; + case NGTCP2_PKT_STATELESS_RESET: + return "SR"; + case NGTCP2_PKT_1RTT: + return "1RTT"; + default: + return "(unknown)"; + } +} + +static const char *strpkttype_type_flags(uint8_t type, uint8_t flags) { + ngtcp2_pkt_hd hd = {0}; + + hd.type = type; + hd.flags = flags; + + return strpkttype(&hd); +} + +static const char *strevent(ngtcp2_log_event ev) { + switch (ev) { + case NGTCP2_LOG_EVENT_CON: + return "con"; + case NGTCP2_LOG_EVENT_PKT: + return "pkt"; + case NGTCP2_LOG_EVENT_FRM: + return "frm"; + case NGTCP2_LOG_EVENT_RCV: + return "rcv"; + case NGTCP2_LOG_EVENT_CRY: + return "cry"; + case NGTCP2_LOG_EVENT_PTV: + return "ptv"; + case NGTCP2_LOG_EVENT_NONE: + default: + return "non"; + } +} + +static uint64_t timestamp_cast(uint64_t ns) { return ns / NGTCP2_MILLISECONDS; } + +static void log_fr_stream(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_stream *fr, const char *dir) { + log->log_printf( + log->user_data, + (NGTCP2_LOG_PKT " STREAM(0x%02x) id=0x%" PRIx64 " fin=%d offset=%" PRIu64 + " len=%" PRIu64 " uni=%d"), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type | fr->flags, fr->stream_id, + fr->fin, fr->offset, ngtcp2_vec_len(fr->data, fr->datacnt), + (fr->stream_id & 0x2) != 0); +} + +static void log_fr_ack(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_ack *fr, const char *dir) { + int64_t largest_ack, min_ack; + size_t i; + + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " ACK(0x%02x) largest_ack=%" PRId64 + " ack_delay=%" PRIu64 "(%" PRIu64 + ") ack_range_count=%zu"), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->largest_ack, + fr->ack_delay_unscaled / NGTCP2_MILLISECONDS, fr->ack_delay, + fr->rangecnt); + + largest_ack = fr->largest_ack; + min_ack = fr->largest_ack - (int64_t)fr->first_ack_range; + + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " ACK(0x%02x) range=[%" PRId64 "..%" PRId64 + "] len=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, largest_ack, min_ack, + fr->first_ack_range); + + for (i = 0; i < fr->rangecnt; ++i) { + const ngtcp2_ack_range *range = &fr->ranges[i]; + largest_ack = min_ack - (int64_t)range->gap - 2; + min_ack = largest_ack - (int64_t)range->len; + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " ACK(0x%02x) range=[%" PRId64 "..%" PRId64 + "] gap=%" PRIu64 " len=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, largest_ack, + min_ack, range->gap, range->len); + } + + if (fr->type == NGTCP2_FRAME_ACK_ECN) { + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " ACK(0x%02x) ect0=%" PRIu64 + " ect1=%" PRIu64 " ce=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->ecn.ect0, + fr->ecn.ect1, fr->ecn.ce); + } +} + +static void log_fr_padding(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_padding *fr, const char *dir) { + log->log_printf(log->user_data, (NGTCP2_LOG_PKT " PADDING(0x%02x) len=%zu"), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->len); +} + +static void log_fr_reset_stream(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_reset_stream *fr, + const char *dir) { + log->log_printf( + log->user_data, + (NGTCP2_LOG_PKT " RESET_STREAM(0x%02x) id=0x%" PRIx64 + " app_error_code=%s(0x%" PRIx64 ") final_size=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id, + strapperrorcode(fr->app_error_code), fr->app_error_code, fr->final_size); +} + +static void log_fr_connection_close(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_connection_close *fr, + const char *dir) { + char reason[256]; + size_t reasonlen = ngtcp2_min(sizeof(reason) - 1, fr->reasonlen); + + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT + " CONNECTION_CLOSE(0x%02x) error_code=%s(0x%" PRIx64 ") " + "frame_type=%" PRIx64 " reason_len=%zu reason=[%s]"), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, + fr->type == NGTCP2_FRAME_CONNECTION_CLOSE + ? strerrorcode(fr->error_code) + : strapperrorcode(fr->error_code), + fr->error_code, fr->frame_type, fr->reasonlen, + ngtcp2_encode_printable_ascii(reason, fr->reason, reasonlen)); +} + +static void log_fr_max_data(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_max_data *fr, const char *dir) { + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " MAX_DATA(0x%02x) max_data=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->max_data); +} + +static void log_fr_max_stream_data(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_max_stream_data *fr, + const char *dir) { + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " MAX_STREAM_DATA(0x%02x) id=0x%" PRIx64 + " max_stream_data=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id, + fr->max_stream_data); +} + +static void log_fr_max_streams(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_max_streams *fr, const char *dir) { + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " MAX_STREAMS(0x%02x) max_streams=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->max_streams); +} + +static void log_fr_ping(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_ping *fr, const char *dir) { + log->log_printf(log->user_data, (NGTCP2_LOG_PKT " PING(0x%02x)"), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type); +} + +static void log_fr_data_blocked(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_data_blocked *fr, + const char *dir) { + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " DATA_BLOCKED(0x%02x) offset=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->offset); +} + +static void log_fr_stream_data_blocked(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_stream_data_blocked *fr, + const char *dir) { + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " STREAM_DATA_BLOCKED(0x%02x) id=0x%" PRIx64 + " offset=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id, + fr->offset); +} + +static void log_fr_streams_blocked(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_streams_blocked *fr, + const char *dir) { + log->log_printf( + log->user_data, + (NGTCP2_LOG_PKT " STREAMS_BLOCKED(0x%02x) max_streams=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->max_streams); +} + +static void log_fr_new_connection_id(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_new_connection_id *fr, + const char *dir) { + uint8_t buf[sizeof(fr->stateless_reset_token) * 2 + 1]; + uint8_t cid[sizeof(fr->cid.data) * 2 + 1]; + + log->log_printf( + log->user_data, + (NGTCP2_LOG_PKT " NEW_CONNECTION_ID(0x%02x) seq=%" PRIu64 + " cid=0x%s retire_prior_to=%" PRIu64 + " stateless_reset_token=0x%s"), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->seq, + (const char *)ngtcp2_encode_hex(cid, fr->cid.data, fr->cid.datalen), + fr->retire_prior_to, + (const char *)ngtcp2_encode_hex(buf, fr->stateless_reset_token, + sizeof(fr->stateless_reset_token))); +} + +static void log_fr_stop_sending(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_stop_sending *fr, + const char *dir) { + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " STOP_SENDING(0x%02x) id=0x%" PRIx64 + " app_error_code=%s(0x%" PRIx64 ")"), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id, + strapperrorcode(fr->app_error_code), fr->app_error_code); +} + +static void log_fr_path_challenge(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_path_challenge *fr, + const char *dir) { + uint8_t buf[sizeof(fr->data) * 2 + 1]; + + log->log_printf( + log->user_data, (NGTCP2_LOG_PKT " PATH_CHALLENGE(0x%02x) data=0x%s"), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, + (const char *)ngtcp2_encode_hex(buf, fr->data, sizeof(fr->data))); +} + +static void log_fr_path_response(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_path_response *fr, + const char *dir) { + uint8_t buf[sizeof(fr->data) * 2 + 1]; + + log->log_printf( + log->user_data, (NGTCP2_LOG_PKT " PATH_RESPONSE(0x%02x) data=0x%s"), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, + (const char *)ngtcp2_encode_hex(buf, fr->data, sizeof(fr->data))); +} + +static void log_fr_crypto(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_crypto *fr, const char *dir) { + log->log_printf( + log->user_data, + (NGTCP2_LOG_PKT " CRYPTO(0x%02x) offset=%" PRIu64 " len=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->offset, + ngtcp2_vec_len(fr->data, fr->datacnt)); +} + +static void log_fr_new_token(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_new_token *fr, const char *dir) { + /* Show at most first 64 bytes of token. If token is longer than 64 + bytes, log first 64 bytes and then append "*" */ + uint8_t buf[128 + 1 + 1]; + uint8_t *p; + + if (fr->token.len > 64) { + p = ngtcp2_encode_hex(buf, fr->token.base, 64); + p[128] = '*'; + p[129] = '\0'; + } else { + p = ngtcp2_encode_hex(buf, fr->token.base, fr->token.len); + } + log->log_printf( + log->user_data, (NGTCP2_LOG_PKT " NEW_TOKEN(0x%02x) token=0x%s len=%zu"), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, (const char *)p, fr->token.len); +} + +static void log_fr_retire_connection_id(ngtcp2_log *log, + const ngtcp2_pkt_hd *hd, + const ngtcp2_retire_connection_id *fr, + const char *dir) { + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " RETIRE_CONNECTION_ID(0x%02x) seq=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->seq); +} + +static void log_fr_handshake_done(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_handshake_done *fr, + const char *dir) { + log->log_printf(log->user_data, (NGTCP2_LOG_PKT " HANDSHAKE_DONE(0x%02x)"), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type); +} + +static void log_fr_datagram(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_datagram *fr, const char *dir) { + log->log_printf(log->user_data, + (NGTCP2_LOG_PKT " DATAGRAM(0x%02x) len=%" PRIu64), + NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, + ngtcp2_vec_len(fr->data, fr->datacnt)); +} + +static void log_fr(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_frame *fr, const char *dir) { + switch (fr->type) { + case NGTCP2_FRAME_STREAM: + log_fr_stream(log, hd, &fr->stream, dir); + break; + case NGTCP2_FRAME_ACK: + case NGTCP2_FRAME_ACK_ECN: + log_fr_ack(log, hd, &fr->ack, dir); + break; + case NGTCP2_FRAME_PADDING: + log_fr_padding(log, hd, &fr->padding, dir); + break; + case NGTCP2_FRAME_RESET_STREAM: + log_fr_reset_stream(log, hd, &fr->reset_stream, dir); + break; + case NGTCP2_FRAME_CONNECTION_CLOSE: + case NGTCP2_FRAME_CONNECTION_CLOSE_APP: + log_fr_connection_close(log, hd, &fr->connection_close, dir); + break; + case NGTCP2_FRAME_MAX_DATA: + log_fr_max_data(log, hd, &fr->max_data, dir); + break; + case NGTCP2_FRAME_MAX_STREAM_DATA: + log_fr_max_stream_data(log, hd, &fr->max_stream_data, dir); + break; + case NGTCP2_FRAME_MAX_STREAMS_BIDI: + case NGTCP2_FRAME_MAX_STREAMS_UNI: + log_fr_max_streams(log, hd, &fr->max_streams, dir); + break; + case NGTCP2_FRAME_PING: + log_fr_ping(log, hd, &fr->ping, dir); + break; + case NGTCP2_FRAME_DATA_BLOCKED: + log_fr_data_blocked(log, hd, &fr->data_blocked, dir); + break; + case NGTCP2_FRAME_STREAM_DATA_BLOCKED: + log_fr_stream_data_blocked(log, hd, &fr->stream_data_blocked, dir); + break; + case NGTCP2_FRAME_STREAMS_BLOCKED_BIDI: + case NGTCP2_FRAME_STREAMS_BLOCKED_UNI: + log_fr_streams_blocked(log, hd, &fr->streams_blocked, dir); + break; + case NGTCP2_FRAME_NEW_CONNECTION_ID: + log_fr_new_connection_id(log, hd, &fr->new_connection_id, dir); + break; + case NGTCP2_FRAME_STOP_SENDING: + log_fr_stop_sending(log, hd, &fr->stop_sending, dir); + break; + case NGTCP2_FRAME_PATH_CHALLENGE: + log_fr_path_challenge(log, hd, &fr->path_challenge, dir); + break; + case NGTCP2_FRAME_PATH_RESPONSE: + log_fr_path_response(log, hd, &fr->path_response, dir); + break; + case NGTCP2_FRAME_CRYPTO: + log_fr_crypto(log, hd, &fr->crypto, dir); + break; + case NGTCP2_FRAME_NEW_TOKEN: + log_fr_new_token(log, hd, &fr->new_token, dir); + break; + case NGTCP2_FRAME_RETIRE_CONNECTION_ID: + log_fr_retire_connection_id(log, hd, &fr->retire_connection_id, dir); + break; + case NGTCP2_FRAME_HANDSHAKE_DONE: + log_fr_handshake_done(log, hd, &fr->handshake_done, dir); + break; + case NGTCP2_FRAME_DATAGRAM: + case NGTCP2_FRAME_DATAGRAM_LEN: + log_fr_datagram(log, hd, &fr->datagram, dir); + break; + default: + ngtcp2_unreachable(); + } +} + +void ngtcp2_log_rx_fr(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_frame *fr) { + if (!log->log_printf) { + return; + } + + log_fr(log, hd, fr, "rx"); +} + +void ngtcp2_log_tx_fr(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const ngtcp2_frame *fr) { + if (!log->log_printf) { + return; + } + + log_fr(log, hd, fr, "tx"); +} + +void ngtcp2_log_rx_vn(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const uint32_t *sv, size_t nsv) { + size_t i; + + if (!log->log_printf) { + return; + } + + for (i = 0; i < nsv; ++i) { + log->log_printf(log->user_data, (NGTCP2_LOG_PKT " v=0x%08x"), + NGTCP2_LOG_PKT_HD_FIELDS("rx"), sv[i]); + } +} + +void ngtcp2_log_rx_sr(ngtcp2_log *log, const ngtcp2_pkt_stateless_reset *sr) { + uint8_t buf[sizeof(sr->stateless_reset_token) * 2 + 1]; + ngtcp2_pkt_hd shd; + ngtcp2_pkt_hd *hd = &shd; + + if (!log->log_printf) { + return; + } + + memset(&shd, 0, sizeof(shd)); + + shd.type = NGTCP2_PKT_STATELESS_RESET; + + log->log_printf( + log->user_data, (NGTCP2_LOG_PKT " token=0x%s randlen=%zu"), + NGTCP2_LOG_PKT_HD_FIELDS("rx"), + (const char *)ngtcp2_encode_hex(buf, sr->stateless_reset_token, + sizeof(sr->stateless_reset_token)), + sr->randlen); +} + +void ngtcp2_log_remote_tp(ngtcp2_log *log, uint8_t exttype, + const ngtcp2_transport_params *params) { + uint8_t token[NGTCP2_STATELESS_RESET_TOKENLEN * 2 + 1]; + uint8_t addr[16 * 2 + 7 + 1]; + uint8_t cid[NGTCP2_MAX_CIDLEN * 2 + 1]; + size_t i; + const ngtcp2_sockaddr_in *sa_in; + const ngtcp2_sockaddr_in6 *sa_in6; + const uint8_t *p; + uint32_t version; + + if (!log->log_printf) { + return; + } + + if (exttype == NGTCP2_TRANSPORT_PARAMS_TYPE_ENCRYPTED_EXTENSIONS) { + if (params->stateless_reset_token_present) { + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " stateless_reset_token=0x%s"), + NGTCP2_LOG_TP_HD_FIELDS, + (const char *)ngtcp2_encode_hex( + token, params->stateless_reset_token, + sizeof(params->stateless_reset_token))); + } + + if (params->preferred_address_present) { + if (params->preferred_address.ipv4_present) { + sa_in = ¶ms->preferred_address.ipv4; + + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " preferred_address.ipv4_addr=%s"), + NGTCP2_LOG_TP_HD_FIELDS, + (const char *)ngtcp2_encode_ipv4( + addr, (const uint8_t *)&sa_in->sin_addr)); + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " preferred_address.ipv4_port=%u"), + NGTCP2_LOG_TP_HD_FIELDS, ngtcp2_ntohs(sa_in->sin_port)); + } + + if (params->preferred_address.ipv6_present) { + sa_in6 = ¶ms->preferred_address.ipv6; + + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " preferred_address.ipv6_addr=%s"), + NGTCP2_LOG_TP_HD_FIELDS, + (const char *)ngtcp2_encode_ipv6( + addr, (const uint8_t *)&sa_in6->sin6_addr)); + log->log_printf( + log->user_data, (NGTCP2_LOG_TP " preferred_address.ipv6_port=%u"), + NGTCP2_LOG_TP_HD_FIELDS, ngtcp2_ntohs(sa_in6->sin6_port)); + } + + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " preferred_address.cid=0x%s"), + NGTCP2_LOG_TP_HD_FIELDS, + (const char *)ngtcp2_encode_hex( + cid, params->preferred_address.cid.data, + params->preferred_address.cid.datalen)); + log->log_printf( + log->user_data, + (NGTCP2_LOG_TP " preferred_address.stateless_reset_token=0x%s"), + NGTCP2_LOG_TP_HD_FIELDS, + (const char *)ngtcp2_encode_hex( + token, params->preferred_address.stateless_reset_token, + sizeof(params->preferred_address.stateless_reset_token))); + } + + log->log_printf( + log->user_data, + (NGTCP2_LOG_TP " original_destination_connection_id=0x%s"), + NGTCP2_LOG_TP_HD_FIELDS, + (const char *)ngtcp2_encode_hex(cid, params->original_dcid.data, + params->original_dcid.datalen)); + + if (params->retry_scid_present) { + log->log_printf( + log->user_data, (NGTCP2_LOG_TP " retry_source_connection_id=0x%s"), + NGTCP2_LOG_TP_HD_FIELDS, + (const char *)ngtcp2_encode_hex(cid, params->retry_scid.data, + params->retry_scid.datalen)); + } + } + + log->log_printf( + log->user_data, (NGTCP2_LOG_TP " initial_source_connection_id=0x%s"), + NGTCP2_LOG_TP_HD_FIELDS, + (const char *)ngtcp2_encode_hex(cid, params->initial_scid.data, + params->initial_scid.datalen)); + + log->log_printf( + log->user_data, + (NGTCP2_LOG_TP " initial_max_stream_data_bidi_local=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_stream_data_bidi_local); + log->log_printf( + log->user_data, + (NGTCP2_LOG_TP " initial_max_stream_data_bidi_remote=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_stream_data_bidi_remote); + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " initial_max_stream_data_uni=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_stream_data_uni); + log->log_printf(log->user_data, (NGTCP2_LOG_TP " initial_max_data=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_data); + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " initial_max_streams_bidi=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_streams_bidi); + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " initial_max_streams_uni=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_streams_uni); + log->log_printf(log->user_data, (NGTCP2_LOG_TP " max_idle_timeout=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, + params->max_idle_timeout / NGTCP2_MILLISECONDS); + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " max_udp_payload_size=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, params->max_udp_payload_size); + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " ack_delay_exponent=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, params->ack_delay_exponent); + log->log_printf(log->user_data, (NGTCP2_LOG_TP " max_ack_delay=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, + params->max_ack_delay / NGTCP2_MILLISECONDS); + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " active_connection_id_limit=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, params->active_connection_id_limit); + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " disable_active_migration=%d"), + NGTCP2_LOG_TP_HD_FIELDS, params->disable_active_migration); + log->log_printf(log->user_data, + (NGTCP2_LOG_TP " max_datagram_frame_size=%" PRIu64), + NGTCP2_LOG_TP_HD_FIELDS, params->max_datagram_frame_size); + log->log_printf(log->user_data, (NGTCP2_LOG_TP " grease_quic_bit=%d"), + NGTCP2_LOG_TP_HD_FIELDS, params->grease_quic_bit); + + if (params->version_info_present) { + log->log_printf( + log->user_data, + (NGTCP2_LOG_TP " version_information.chosen_version=0x%08x"), + NGTCP2_LOG_TP_HD_FIELDS, params->version_info.chosen_version); + + assert(!(params->version_info.other_versionslen & 0x3)); + + for (i = 0, p = params->version_info.other_versions; + i < params->version_info.other_versionslen; i += sizeof(uint32_t)) { + p = ngtcp2_get_uint32(&version, p); + + log->log_printf( + log->user_data, + (NGTCP2_LOG_TP " version_information.other_versions[%zu]=0x%08x"), + NGTCP2_LOG_TP_HD_FIELDS, i >> 2, version); + } + } +} + +void ngtcp2_log_pkt_lost(ngtcp2_log *log, int64_t pkt_num, uint8_t type, + uint8_t flags, ngtcp2_tstamp sent_ts) { + if (!log->log_printf) { + return; + } + + ngtcp2_log_info(log, NGTCP2_LOG_EVENT_RCV, + "pkn=%" PRId64 " lost type=%s sent_ts=%" PRIu64, pkt_num, + strpkttype_type_flags(type, flags), sent_ts); +} + +static void log_pkt_hd(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, + const char *dir) { + uint8_t dcid[sizeof(hd->dcid.data) * 2 + 1]; + uint8_t scid[sizeof(hd->scid.data) * 2 + 1]; + + if (!log->log_printf) { + return; + } + + if (hd->type == NGTCP2_PKT_1RTT) { + ngtcp2_log_info( + log, NGTCP2_LOG_EVENT_PKT, "%s pkn=%" PRId64 " dcid=0x%s type=%s k=%d", + dir, hd->pkt_num, + (const char *)ngtcp2_encode_hex(dcid, hd->dcid.data, hd->dcid.datalen), + strpkttype(hd), (hd->flags & NGTCP2_PKT_FLAG_KEY_PHASE) != 0); + } else { + ngtcp2_log_info( + log, NGTCP2_LOG_EVENT_PKT, + "%s pkn=%" PRId64 " dcid=0x%s scid=0x%s version=0x%08x type=%s len=%zu", + dir, hd->pkt_num, + (const char *)ngtcp2_encode_hex(dcid, hd->dcid.data, hd->dcid.datalen), + (const char *)ngtcp2_encode_hex(scid, hd->scid.data, hd->scid.datalen), + hd->version, strpkttype(hd), hd->len); + } +} + +void ngtcp2_log_rx_pkt_hd(ngtcp2_log *log, const ngtcp2_pkt_hd *hd) { + log_pkt_hd(log, hd, "rx"); +} + +void ngtcp2_log_tx_pkt_hd(ngtcp2_log *log, const ngtcp2_pkt_hd *hd) { + log_pkt_hd(log, hd, "tx"); +} + +void ngtcp2_log_info(ngtcp2_log *log, ngtcp2_log_event ev, const char *fmt, + ...) { + va_list ap; + int n; + char buf[NGTCP2_LOG_BUFLEN]; + + if (!log->log_printf) { + return; + } + + va_start(ap, fmt); + n = vsnprintf(buf, sizeof(buf), fmt, ap); + va_end(ap); + + if (n < 0 || (size_t)n >= sizeof(buf)) { + return; + } + + log->log_printf(log->user_data, (NGTCP2_LOG_HD " %s"), + timestamp_cast(log->last_ts - log->ts), log->scid, + strevent(ev), buf); +} + +void ngtcp2_log_tx_cancel(ngtcp2_log *log, const ngtcp2_pkt_hd *hd) { + ngtcp2_log_info(log, NGTCP2_LOG_EVENT_PKT, + "cancel tx pkn=%" PRId64 " type=%s", hd->pkt_num, + strpkttype(hd)); +} |