1/* 2 * ngtcp2 3 * 4 * Copyright (c) 2018 ngtcp2 contributors 5 * 6 * Permission is hereby granted, free of charge, to any person obtaining 7 * a copy of this software and associated documentation files (the 8 * "Software"), to deal in the Software without restriction, including 9 * without limitation the rights to use, copy, modify, merge, publish, 10 * distribute, sublicense, and/or sell copies of the Software, and to 11 * permit persons to whom the Software is furnished to do so, subject to 12 * the following conditions: 13 * 14 * The above copyright notice and this permission notice shall be 15 * included in all copies or substantial portions of the Software. 16 * 17 * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, 18 * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF 19 * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND 20 * NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE 21 * LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION 22 * OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION 23 * WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. 24 */ 25#include "ngtcp2_log.h" 26 27#include <stdio.h> 28#ifdef HAVE_UNISTD_H 29# include <unistd.h> 30#endif 31#include <assert.h> 32#include <string.h> 33 34#include "ngtcp2_str.h" 35#include "ngtcp2_vec.h" 36#include "ngtcp2_macro.h" 37#include "ngtcp2_conv.h" 38 39void ngtcp2_log_init(ngtcp2_log *log, const ngtcp2_cid *scid, 40 ngtcp2_printf log_printf, ngtcp2_tstamp ts, 41 void *user_data) { 42 if (scid) { 43 ngtcp2_encode_hex(log->scid, scid->data, scid->datalen); 44 } else { 45 log->scid[0] = '\0'; 46 } 47 log->log_printf = log_printf; 48 log->ts = log->last_ts = ts; 49 log->user_data = user_data; 50} 51 52/* 53 * # Log header 54 * 55 * <LEVEL><TIMESTAMP> <SCID> <EVENT> 56 * 57 * <LEVEL>: 58 * Log level. I=Info, W=Warning, E=Error 59 * 60 * <TIMESTAMP>: 61 * Timestamp relative to ngtcp2_log.ts field in milliseconds 62 * resolution. 63 * 64 * <SCID>: 65 * Source Connection ID in hex string. 66 * 67 * <EVENT>: 68 * Event. pkt=packet, frm=frame, rcv=recovery, cry=crypto, 69 * con=connection(catch all) 70 * 71 * # Frame event 72 * 73 * <DIR> <PKN> <PKTNAME> <FRAMENAME>(<FRAMETYPE>) 74 * 75 * <DIR>: 76 * Flow direction. tx=transmission, rx=reception 77 * 78 * <PKN>: 79 * Packet number. 80 * 81 * <PKTNAME>: 82 * Packet name. (e.g., Initial, Handshake, 1RTT) 83 * 84 * <FRAMENAME>: 85 * Frame name. (e.g., STREAM, ACK, PING) 86 * 87 * <FRAMETYPE>: 88 * Frame type in hex string. 89 */ 90 91#define NGTCP2_LOG_BUFLEN 4096 92 93/* TODO Split second and remaining fraction with comma */ 94#define NGTCP2_LOG_HD "I%08" PRIu64 " 0x%s %s" 95#define NGTCP2_LOG_PKT NGTCP2_LOG_HD " %s %" PRId64 " %s" 96#define NGTCP2_LOG_TP NGTCP2_LOG_HD " remote transport_parameters" 97 98#define NGTCP2_LOG_FRM_HD_FIELDS(DIR) \ 99 timestamp_cast(log->last_ts - log->ts), (const char *)log->scid, "frm", \ 100 (DIR), hd->pkt_num, strpkttype(hd) 101 102#define NGTCP2_LOG_PKT_HD_FIELDS(DIR) \ 103 timestamp_cast(log->last_ts - log->ts), (const char *)log->scid, "pkt", \ 104 (DIR), hd->pkt_num, strpkttype(hd) 105 106#define NGTCP2_LOG_TP_HD_FIELDS \ 107 timestamp_cast(log->last_ts - log->ts), (const char *)log->scid, "cry" 108 109static const char *strerrorcode(uint64_t error_code) { 110 switch (error_code) { 111 case NGTCP2_NO_ERROR: 112 return "NO_ERROR"; 113 case NGTCP2_INTERNAL_ERROR: 114 return "INTERNAL_ERROR"; 115 case NGTCP2_CONNECTION_REFUSED: 116 return "CONNECTION_REFUSED"; 117 case NGTCP2_FLOW_CONTROL_ERROR: 118 return "FLOW_CONTROL_ERROR"; 119 case NGTCP2_STREAM_LIMIT_ERROR: 120 return "STREAM_LIMIT_ERROR"; 121 case NGTCP2_STREAM_STATE_ERROR: 122 return "STREAM_STATE_ERROR"; 123 case NGTCP2_FINAL_SIZE_ERROR: 124 return "FINAL_SIZE_ERROR"; 125 case NGTCP2_FRAME_ENCODING_ERROR: 126 return "FRAME_ENCODING_ERROR"; 127 case NGTCP2_TRANSPORT_PARAMETER_ERROR: 128 return "TRANSPORT_PARAMETER_ERROR"; 129 case NGTCP2_CONNECTION_ID_LIMIT_ERROR: 130 return "CONNECTION_ID_LIMIT_ERROR"; 131 case NGTCP2_PROTOCOL_VIOLATION: 132 return "PROTOCOL_VIOLATION"; 133 case NGTCP2_INVALID_TOKEN: 134 return "INVALID_TOKEN"; 135 case NGTCP2_APPLICATION_ERROR: 136 return "APPLICATION_ERROR"; 137 case NGTCP2_CRYPTO_BUFFER_EXCEEDED: 138 return "CRYPTO_BUFFER_EXCEEDED"; 139 case NGTCP2_KEY_UPDATE_ERROR: 140 return "KEY_UPDATE_ERROR"; 141 case NGTCP2_VERSION_NEGOTIATION_ERROR_DRAFT: 142 return "VERSION_NEGOTIATION_ERROR"; 143 default: 144 if (0x100u <= error_code && error_code <= 0x1ffu) { 145 return "CRYPTO_ERROR"; 146 } 147 return "(unknown)"; 148 } 149} 150 151static const char *strapperrorcode(uint64_t app_error_code) { 152 (void)app_error_code; 153 return "(unknown)"; 154} 155 156static const char *strpkttype_long(uint8_t type) { 157 switch (type) { 158 case NGTCP2_PKT_INITIAL: 159 return "Initial"; 160 case NGTCP2_PKT_RETRY: 161 return "Retry"; 162 case NGTCP2_PKT_HANDSHAKE: 163 return "Handshake"; 164 case NGTCP2_PKT_0RTT: 165 return "0RTT"; 166 default: 167 return "(unknown)"; 168 } 169} 170 171static const char *strpkttype(const ngtcp2_pkt_hd *hd) { 172 if (hd->flags & NGTCP2_PKT_FLAG_LONG_FORM) { 173 return strpkttype_long(hd->type); 174 } 175 176 switch (hd->type) { 177 case NGTCP2_PKT_VERSION_NEGOTIATION: 178 return "VN"; 179 case NGTCP2_PKT_STATELESS_RESET: 180 return "SR"; 181 case NGTCP2_PKT_1RTT: 182 return "1RTT"; 183 default: 184 return "(unknown)"; 185 } 186} 187 188static const char *strpkttype_type_flags(uint8_t type, uint8_t flags) { 189 ngtcp2_pkt_hd hd = {0}; 190 191 hd.type = type; 192 hd.flags = flags; 193 194 return strpkttype(&hd); 195} 196 197static const char *strevent(ngtcp2_log_event ev) { 198 switch (ev) { 199 case NGTCP2_LOG_EVENT_CON: 200 return "con"; 201 case NGTCP2_LOG_EVENT_PKT: 202 return "pkt"; 203 case NGTCP2_LOG_EVENT_FRM: 204 return "frm"; 205 case NGTCP2_LOG_EVENT_RCV: 206 return "rcv"; 207 case NGTCP2_LOG_EVENT_CRY: 208 return "cry"; 209 case NGTCP2_LOG_EVENT_PTV: 210 return "ptv"; 211 case NGTCP2_LOG_EVENT_NONE: 212 default: 213 return "non"; 214 } 215} 216 217static uint64_t timestamp_cast(uint64_t ns) { return ns / NGTCP2_MILLISECONDS; } 218 219static void log_fr_stream(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 220 const ngtcp2_stream *fr, const char *dir) { 221 log->log_printf( 222 log->user_data, 223 (NGTCP2_LOG_PKT " STREAM(0x%02x) id=0x%" PRIx64 " fin=%d offset=%" PRIu64 224 " len=%" PRIu64 " uni=%d"), 225 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type | fr->flags, fr->stream_id, 226 fr->fin, fr->offset, ngtcp2_vec_len(fr->data, fr->datacnt), 227 (fr->stream_id & 0x2) != 0); 228} 229 230static void log_fr_ack(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 231 const ngtcp2_ack *fr, const char *dir) { 232 int64_t largest_ack, min_ack; 233 size_t i; 234 235 log->log_printf(log->user_data, 236 (NGTCP2_LOG_PKT " ACK(0x%02x) largest_ack=%" PRId64 237 " ack_delay=%" PRIu64 "(%" PRIu64 238 ") ack_block_count=%zu"), 239 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->largest_ack, 240 fr->ack_delay_unscaled / NGTCP2_MILLISECONDS, fr->ack_delay, 241 fr->num_blks); 242 243 largest_ack = fr->largest_ack; 244 min_ack = fr->largest_ack - (int64_t)fr->first_ack_blklen; 245 246 log->log_printf(log->user_data, 247 (NGTCP2_LOG_PKT " ACK(0x%02x) block=[%" PRId64 "..%" PRId64 248 "] block_count=%" PRIu64), 249 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, largest_ack, min_ack, 250 fr->first_ack_blklen); 251 252 for (i = 0; i < fr->num_blks; ++i) { 253 const ngtcp2_ack_blk *blk = &fr->blks[i]; 254 largest_ack = min_ack - (int64_t)blk->gap - 2; 255 min_ack = largest_ack - (int64_t)blk->blklen; 256 log->log_printf(log->user_data, 257 (NGTCP2_LOG_PKT " ACK(0x%02x) block=[%" PRId64 "..%" PRId64 258 "] gap=%" PRIu64 " block_count=%" PRIu64), 259 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, largest_ack, 260 min_ack, blk->gap, blk->blklen); 261 } 262 263 if (fr->type == NGTCP2_FRAME_ACK_ECN) { 264 log->log_printf(log->user_data, 265 (NGTCP2_LOG_PKT " ACK(0x%02x) ect0=%" PRIu64 266 " ect1=%" PRIu64 " ce=%" PRIu64), 267 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->ecn.ect0, 268 fr->ecn.ect1, fr->ecn.ce); 269 } 270} 271 272static void log_fr_padding(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 273 const ngtcp2_padding *fr, const char *dir) { 274 log->log_printf(log->user_data, (NGTCP2_LOG_PKT " PADDING(0x%02x) len=%zu"), 275 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->len); 276} 277 278static void log_fr_reset_stream(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 279 const ngtcp2_reset_stream *fr, 280 const char *dir) { 281 log->log_printf( 282 log->user_data, 283 (NGTCP2_LOG_PKT " RESET_STREAM(0x%02x) id=0x%" PRIx64 284 " app_error_code=%s(0x%" PRIx64 ") final_size=%" PRIu64), 285 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id, 286 strapperrorcode(fr->app_error_code), fr->app_error_code, fr->final_size); 287} 288 289static void log_fr_connection_close(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 290 const ngtcp2_connection_close *fr, 291 const char *dir) { 292 char reason[256]; 293 size_t reasonlen = ngtcp2_min(sizeof(reason) - 1, fr->reasonlen); 294 295 log->log_printf(log->user_data, 296 (NGTCP2_LOG_PKT 297 " CONNECTION_CLOSE(0x%02x) error_code=%s(0x%" PRIx64 ") " 298 "frame_type=%" PRIx64 " reason_len=%zu reason=[%s]"), 299 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, 300 fr->type == NGTCP2_FRAME_CONNECTION_CLOSE 301 ? strerrorcode(fr->error_code) 302 : strapperrorcode(fr->error_code), 303 fr->error_code, fr->frame_type, fr->reasonlen, 304 ngtcp2_encode_printable_ascii(reason, fr->reason, reasonlen)); 305} 306 307static void log_fr_max_data(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 308 const ngtcp2_max_data *fr, const char *dir) { 309 log->log_printf(log->user_data, 310 (NGTCP2_LOG_PKT " MAX_DATA(0x%02x) max_data=%" PRIu64), 311 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->max_data); 312} 313 314static void log_fr_max_stream_data(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 315 const ngtcp2_max_stream_data *fr, 316 const char *dir) { 317 log->log_printf(log->user_data, 318 (NGTCP2_LOG_PKT " MAX_STREAM_DATA(0x%02x) id=0x%" PRIx64 319 " max_stream_data=%" PRIu64), 320 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id, 321 fr->max_stream_data); 322} 323 324static void log_fr_max_streams(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 325 const ngtcp2_max_streams *fr, const char *dir) { 326 log->log_printf(log->user_data, 327 (NGTCP2_LOG_PKT " MAX_STREAMS(0x%02x) max_streams=%" PRIu64), 328 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->max_streams); 329} 330 331static void log_fr_ping(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 332 const ngtcp2_ping *fr, const char *dir) { 333 log->log_printf(log->user_data, (NGTCP2_LOG_PKT " PING(0x%02x)"), 334 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type); 335} 336 337static void log_fr_data_blocked(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 338 const ngtcp2_data_blocked *fr, 339 const char *dir) { 340 log->log_printf(log->user_data, 341 (NGTCP2_LOG_PKT " DATA_BLOCKED(0x%02x) offset=%" PRIu64), 342 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->offset); 343} 344 345static void log_fr_stream_data_blocked(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 346 const ngtcp2_stream_data_blocked *fr, 347 const char *dir) { 348 log->log_printf(log->user_data, 349 (NGTCP2_LOG_PKT " STREAM_DATA_BLOCKED(0x%02x) id=0x%" PRIx64 350 " offset=%" PRIu64), 351 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id, 352 fr->offset); 353} 354 355static void log_fr_streams_blocked(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 356 const ngtcp2_streams_blocked *fr, 357 const char *dir) { 358 log->log_printf( 359 log->user_data, 360 (NGTCP2_LOG_PKT " STREAMS_BLOCKED(0x%02x) max_streams=%" PRIu64), 361 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->max_streams); 362} 363 364static void log_fr_new_connection_id(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 365 const ngtcp2_new_connection_id *fr, 366 const char *dir) { 367 uint8_t buf[sizeof(fr->stateless_reset_token) * 2 + 1]; 368 uint8_t cid[sizeof(fr->cid.data) * 2 + 1]; 369 370 log->log_printf( 371 log->user_data, 372 (NGTCP2_LOG_PKT " NEW_CONNECTION_ID(0x%02x) seq=%" PRIu64 373 " cid=0x%s retire_prior_to=%" PRIu64 374 " stateless_reset_token=0x%s"), 375 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->seq, 376 (const char *)ngtcp2_encode_hex(cid, fr->cid.data, fr->cid.datalen), 377 fr->retire_prior_to, 378 (const char *)ngtcp2_encode_hex(buf, fr->stateless_reset_token, 379 sizeof(fr->stateless_reset_token))); 380} 381 382static void log_fr_stop_sending(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 383 const ngtcp2_stop_sending *fr, 384 const char *dir) { 385 log->log_printf(log->user_data, 386 (NGTCP2_LOG_PKT " STOP_SENDING(0x%02x) id=0x%" PRIx64 387 " app_error_code=%s(0x%" PRIx64 ")"), 388 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->stream_id, 389 strapperrorcode(fr->app_error_code), fr->app_error_code); 390} 391 392static void log_fr_path_challenge(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 393 const ngtcp2_path_challenge *fr, 394 const char *dir) { 395 uint8_t buf[sizeof(fr->data) * 2 + 1]; 396 397 log->log_printf( 398 log->user_data, (NGTCP2_LOG_PKT " PATH_CHALLENGE(0x%02x) data=0x%s"), 399 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, 400 (const char *)ngtcp2_encode_hex(buf, fr->data, sizeof(fr->data))); 401} 402 403static void log_fr_path_response(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 404 const ngtcp2_path_response *fr, 405 const char *dir) { 406 uint8_t buf[sizeof(fr->data) * 2 + 1]; 407 408 log->log_printf( 409 log->user_data, (NGTCP2_LOG_PKT " PATH_RESPONSE(0x%02x) data=0x%s"), 410 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, 411 (const char *)ngtcp2_encode_hex(buf, fr->data, sizeof(fr->data))); 412} 413 414static void log_fr_crypto(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 415 const ngtcp2_crypto *fr, const char *dir) { 416 log->log_printf( 417 log->user_data, 418 (NGTCP2_LOG_PKT " CRYPTO(0x%02x) offset=%" PRIu64 " len=%" PRIu64), 419 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->offset, 420 ngtcp2_vec_len(fr->data, fr->datacnt)); 421} 422 423static void log_fr_new_token(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 424 const ngtcp2_new_token *fr, const char *dir) { 425 /* Show at most first 64 bytes of token. If token is longer than 64 426 bytes, log first 64 bytes and then append "*" */ 427 uint8_t buf[128 + 1 + 1]; 428 uint8_t *p; 429 430 if (fr->token.len > 64) { 431 p = ngtcp2_encode_hex(buf, fr->token.base, 64); 432 p[128] = '*'; 433 p[129] = '\0'; 434 } else { 435 p = ngtcp2_encode_hex(buf, fr->token.base, fr->token.len); 436 } 437 log->log_printf( 438 log->user_data, (NGTCP2_LOG_PKT " NEW_TOKEN(0x%02x) token=0x%s len=%zu"), 439 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, (const char *)p, fr->token.len); 440} 441 442static void log_fr_retire_connection_id(ngtcp2_log *log, 443 const ngtcp2_pkt_hd *hd, 444 const ngtcp2_retire_connection_id *fr, 445 const char *dir) { 446 log->log_printf(log->user_data, 447 (NGTCP2_LOG_PKT " RETIRE_CONNECTION_ID(0x%02x) seq=%" PRIu64), 448 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, fr->seq); 449} 450 451static void log_fr_handshake_done(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 452 const ngtcp2_handshake_done *fr, 453 const char *dir) { 454 log->log_printf(log->user_data, (NGTCP2_LOG_PKT " HANDSHAKE_DONE(0x%02x)"), 455 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type); 456} 457 458static void log_fr_datagram(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 459 const ngtcp2_datagram *fr, const char *dir) { 460 log->log_printf(log->user_data, 461 (NGTCP2_LOG_PKT " DATAGRAM(0x%02x) len=%" PRIu64), 462 NGTCP2_LOG_FRM_HD_FIELDS(dir), fr->type, 463 ngtcp2_vec_len(fr->data, fr->datacnt)); 464} 465 466static void log_fr(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 467 const ngtcp2_frame *fr, const char *dir) { 468 switch (fr->type) { 469 case NGTCP2_FRAME_STREAM: 470 log_fr_stream(log, hd, &fr->stream, dir); 471 break; 472 case NGTCP2_FRAME_ACK: 473 case NGTCP2_FRAME_ACK_ECN: 474 log_fr_ack(log, hd, &fr->ack, dir); 475 break; 476 case NGTCP2_FRAME_PADDING: 477 log_fr_padding(log, hd, &fr->padding, dir); 478 break; 479 case NGTCP2_FRAME_RESET_STREAM: 480 log_fr_reset_stream(log, hd, &fr->reset_stream, dir); 481 break; 482 case NGTCP2_FRAME_CONNECTION_CLOSE: 483 case NGTCP2_FRAME_CONNECTION_CLOSE_APP: 484 log_fr_connection_close(log, hd, &fr->connection_close, dir); 485 break; 486 case NGTCP2_FRAME_MAX_DATA: 487 log_fr_max_data(log, hd, &fr->max_data, dir); 488 break; 489 case NGTCP2_FRAME_MAX_STREAM_DATA: 490 log_fr_max_stream_data(log, hd, &fr->max_stream_data, dir); 491 break; 492 case NGTCP2_FRAME_MAX_STREAMS_BIDI: 493 case NGTCP2_FRAME_MAX_STREAMS_UNI: 494 log_fr_max_streams(log, hd, &fr->max_streams, dir); 495 break; 496 case NGTCP2_FRAME_PING: 497 log_fr_ping(log, hd, &fr->ping, dir); 498 break; 499 case NGTCP2_FRAME_DATA_BLOCKED: 500 log_fr_data_blocked(log, hd, &fr->data_blocked, dir); 501 break; 502 case NGTCP2_FRAME_STREAM_DATA_BLOCKED: 503 log_fr_stream_data_blocked(log, hd, &fr->stream_data_blocked, dir); 504 break; 505 case NGTCP2_FRAME_STREAMS_BLOCKED_BIDI: 506 case NGTCP2_FRAME_STREAMS_BLOCKED_UNI: 507 log_fr_streams_blocked(log, hd, &fr->streams_blocked, dir); 508 break; 509 case NGTCP2_FRAME_NEW_CONNECTION_ID: 510 log_fr_new_connection_id(log, hd, &fr->new_connection_id, dir); 511 break; 512 case NGTCP2_FRAME_STOP_SENDING: 513 log_fr_stop_sending(log, hd, &fr->stop_sending, dir); 514 break; 515 case NGTCP2_FRAME_PATH_CHALLENGE: 516 log_fr_path_challenge(log, hd, &fr->path_challenge, dir); 517 break; 518 case NGTCP2_FRAME_PATH_RESPONSE: 519 log_fr_path_response(log, hd, &fr->path_response, dir); 520 break; 521 case NGTCP2_FRAME_CRYPTO: 522 log_fr_crypto(log, hd, &fr->crypto, dir); 523 break; 524 case NGTCP2_FRAME_NEW_TOKEN: 525 log_fr_new_token(log, hd, &fr->new_token, dir); 526 break; 527 case NGTCP2_FRAME_RETIRE_CONNECTION_ID: 528 log_fr_retire_connection_id(log, hd, &fr->retire_connection_id, dir); 529 break; 530 case NGTCP2_FRAME_HANDSHAKE_DONE: 531 log_fr_handshake_done(log, hd, &fr->handshake_done, dir); 532 break; 533 case NGTCP2_FRAME_DATAGRAM: 534 case NGTCP2_FRAME_DATAGRAM_LEN: 535 log_fr_datagram(log, hd, &fr->datagram, dir); 536 break; 537 default: 538 assert(0); 539 } 540} 541 542void ngtcp2_log_rx_fr(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 543 const ngtcp2_frame *fr) { 544 if (!log->log_printf) { 545 return; 546 } 547 548 log_fr(log, hd, fr, "rx"); 549} 550 551void ngtcp2_log_tx_fr(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 552 const ngtcp2_frame *fr) { 553 if (!log->log_printf) { 554 return; 555 } 556 557 log_fr(log, hd, fr, "tx"); 558} 559 560void ngtcp2_log_rx_vn(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 561 const uint32_t *sv, size_t nsv) { 562 size_t i; 563 564 if (!log->log_printf) { 565 return; 566 } 567 568 for (i = 0; i < nsv; ++i) { 569 log->log_printf(log->user_data, (NGTCP2_LOG_PKT " v=0x%08x"), 570 NGTCP2_LOG_PKT_HD_FIELDS("rx"), sv[i]); 571 } 572} 573 574void ngtcp2_log_rx_sr(ngtcp2_log *log, const ngtcp2_pkt_stateless_reset *sr) { 575 uint8_t buf[sizeof(sr->stateless_reset_token) * 2 + 1]; 576 ngtcp2_pkt_hd shd; 577 ngtcp2_pkt_hd *hd = &shd; 578 579 if (!log->log_printf) { 580 return; 581 } 582 583 memset(&shd, 0, sizeof(shd)); 584 585 shd.type = NGTCP2_PKT_STATELESS_RESET; 586 587 log->log_printf( 588 log->user_data, (NGTCP2_LOG_PKT " token=0x%s randlen=%zu"), 589 NGTCP2_LOG_PKT_HD_FIELDS("rx"), 590 (const char *)ngtcp2_encode_hex(buf, sr->stateless_reset_token, 591 sizeof(sr->stateless_reset_token)), 592 sr->randlen); 593} 594 595void ngtcp2_log_remote_tp(ngtcp2_log *log, uint8_t exttype, 596 const ngtcp2_transport_params *params) { 597 uint8_t token[NGTCP2_STATELESS_RESET_TOKENLEN * 2 + 1]; 598 uint8_t addr[16 * 2 + 7 + 1]; 599 uint8_t cid[NGTCP2_MAX_CIDLEN * 2 + 1]; 600 size_t i; 601 602 if (!log->log_printf) { 603 return; 604 } 605 606 if (exttype == NGTCP2_TRANSPORT_PARAMS_TYPE_ENCRYPTED_EXTENSIONS) { 607 if (params->stateless_reset_token_present) { 608 log->log_printf(log->user_data, 609 (NGTCP2_LOG_TP " stateless_reset_token=0x%s"), 610 NGTCP2_LOG_TP_HD_FIELDS, 611 (const char *)ngtcp2_encode_hex( 612 token, params->stateless_reset_token, 613 sizeof(params->stateless_reset_token))); 614 } 615 616 if (params->preferred_address_present) { 617 log->log_printf(log->user_data, 618 (NGTCP2_LOG_TP " preferred_address.ipv4_addr=%s"), 619 NGTCP2_LOG_TP_HD_FIELDS, 620 (const char *)ngtcp2_encode_ipv4( 621 addr, params->preferred_address.ipv4_addr)); 622 log->log_printf( 623 log->user_data, (NGTCP2_LOG_TP " preferred_address.ipv4_port=%u"), 624 NGTCP2_LOG_TP_HD_FIELDS, params->preferred_address.ipv4_port); 625 626 log->log_printf(log->user_data, 627 (NGTCP2_LOG_TP " preferred_address.ipv6_addr=%s"), 628 NGTCP2_LOG_TP_HD_FIELDS, 629 (const char *)ngtcp2_encode_ipv6( 630 addr, params->preferred_address.ipv6_addr)); 631 log->log_printf( 632 log->user_data, (NGTCP2_LOG_TP " preferred_address.ipv6_port=%u"), 633 NGTCP2_LOG_TP_HD_FIELDS, params->preferred_address.ipv6_port); 634 635 log->log_printf(log->user_data, 636 (NGTCP2_LOG_TP " preferred_address.cid=0x%s"), 637 NGTCP2_LOG_TP_HD_FIELDS, 638 (const char *)ngtcp2_encode_hex( 639 cid, params->preferred_address.cid.data, 640 params->preferred_address.cid.datalen)); 641 log->log_printf( 642 log->user_data, 643 (NGTCP2_LOG_TP " preferred_address.stateless_reset_token=0x%s"), 644 NGTCP2_LOG_TP_HD_FIELDS, 645 (const char *)ngtcp2_encode_hex( 646 token, params->preferred_address.stateless_reset_token, 647 sizeof(params->preferred_address.stateless_reset_token))); 648 } 649 650 log->log_printf( 651 log->user_data, 652 (NGTCP2_LOG_TP " original_destination_connection_id=0x%s"), 653 NGTCP2_LOG_TP_HD_FIELDS, 654 (const char *)ngtcp2_encode_hex(cid, params->original_dcid.data, 655 params->original_dcid.datalen)); 656 657 if (params->retry_scid_present) { 658 log->log_printf( 659 log->user_data, (NGTCP2_LOG_TP " retry_source_connection_id=0x%s"), 660 NGTCP2_LOG_TP_HD_FIELDS, 661 (const char *)ngtcp2_encode_hex(cid, params->retry_scid.data, 662 params->retry_scid.datalen)); 663 } 664 } 665 666 log->log_printf( 667 log->user_data, (NGTCP2_LOG_TP " initial_source_connection_id=0x%s"), 668 NGTCP2_LOG_TP_HD_FIELDS, 669 (const char *)ngtcp2_encode_hex(cid, params->initial_scid.data, 670 params->initial_scid.datalen)); 671 672 log->log_printf( 673 log->user_data, 674 (NGTCP2_LOG_TP " initial_max_stream_data_bidi_local=%" PRIu64), 675 NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_stream_data_bidi_local); 676 log->log_printf( 677 log->user_data, 678 (NGTCP2_LOG_TP " initial_max_stream_data_bidi_remote=%" PRIu64), 679 NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_stream_data_bidi_remote); 680 log->log_printf(log->user_data, 681 (NGTCP2_LOG_TP " initial_max_stream_data_uni=%" PRIu64), 682 NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_stream_data_uni); 683 log->log_printf(log->user_data, (NGTCP2_LOG_TP " initial_max_data=%" PRIu64), 684 NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_data); 685 log->log_printf(log->user_data, 686 (NGTCP2_LOG_TP " initial_max_streams_bidi=%" PRIu64), 687 NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_streams_bidi); 688 log->log_printf(log->user_data, 689 (NGTCP2_LOG_TP " initial_max_streams_uni=%" PRIu64), 690 NGTCP2_LOG_TP_HD_FIELDS, params->initial_max_streams_uni); 691 log->log_printf(log->user_data, (NGTCP2_LOG_TP " max_idle_timeout=%" PRIu64), 692 NGTCP2_LOG_TP_HD_FIELDS, 693 params->max_idle_timeout / NGTCP2_MILLISECONDS); 694 log->log_printf(log->user_data, 695 (NGTCP2_LOG_TP " max_udp_payload_size=%" PRIu64), 696 NGTCP2_LOG_TP_HD_FIELDS, params->max_udp_payload_size); 697 log->log_printf(log->user_data, 698 (NGTCP2_LOG_TP " ack_delay_exponent=%" PRIu64), 699 NGTCP2_LOG_TP_HD_FIELDS, params->ack_delay_exponent); 700 log->log_printf(log->user_data, (NGTCP2_LOG_TP " max_ack_delay=%" PRIu64), 701 NGTCP2_LOG_TP_HD_FIELDS, 702 params->max_ack_delay / NGTCP2_MILLISECONDS); 703 log->log_printf(log->user_data, 704 (NGTCP2_LOG_TP " active_connection_id_limit=%" PRIu64), 705 NGTCP2_LOG_TP_HD_FIELDS, params->active_connection_id_limit); 706 log->log_printf(log->user_data, 707 (NGTCP2_LOG_TP " disable_active_migration=%d"), 708 NGTCP2_LOG_TP_HD_FIELDS, params->disable_active_migration); 709 log->log_printf(log->user_data, 710 (NGTCP2_LOG_TP " max_datagram_frame_size=%" PRIu64), 711 NGTCP2_LOG_TP_HD_FIELDS, params->max_datagram_frame_size); 712 log->log_printf(log->user_data, (NGTCP2_LOG_TP " grease_quic_bit=%d"), 713 NGTCP2_LOG_TP_HD_FIELDS, params->grease_quic_bit); 714 715 if (params->version_info_present) { 716 log->log_printf( 717 log->user_data, 718 (NGTCP2_LOG_TP " version_information.chosen_version=0x%08x"), 719 NGTCP2_LOG_TP_HD_FIELDS, params->version_info.chosen_version); 720 721 assert(!(params->version_info.other_versionslen & 0x3)); 722 723 for (i = 0; i < params->version_info.other_versionslen; 724 i += sizeof(uint32_t)) { 725 log->log_printf( 726 log->user_data, 727 (NGTCP2_LOG_TP " version_information.other_versions[%zu]=0x%08x"), 728 NGTCP2_LOG_TP_HD_FIELDS, i >> 2, 729 ngtcp2_get_uint32(¶ms->version_info.other_versions[i])); 730 } 731 } 732} 733 734void ngtcp2_log_pkt_lost(ngtcp2_log *log, int64_t pkt_num, uint8_t type, 735 uint8_t flags, ngtcp2_tstamp sent_ts) { 736 if (!log->log_printf) { 737 return; 738 } 739 740 ngtcp2_log_info(log, NGTCP2_LOG_EVENT_RCV, 741 "pkn=%" PRId64 " lost type=%s sent_ts=%" PRIu64, pkt_num, 742 strpkttype_type_flags(type, flags), sent_ts); 743} 744 745static void log_pkt_hd(ngtcp2_log *log, const ngtcp2_pkt_hd *hd, 746 const char *dir) { 747 uint8_t dcid[sizeof(hd->dcid.data) * 2 + 1]; 748 uint8_t scid[sizeof(hd->scid.data) * 2 + 1]; 749 750 if (!log->log_printf) { 751 return; 752 } 753 754 if (hd->type == NGTCP2_PKT_1RTT) { 755 ngtcp2_log_info( 756 log, NGTCP2_LOG_EVENT_PKT, "%s pkn=%" PRId64 " dcid=0x%s type=%s k=%d", 757 dir, hd->pkt_num, 758 (const char *)ngtcp2_encode_hex(dcid, hd->dcid.data, hd->dcid.datalen), 759 strpkttype(hd), (hd->flags & NGTCP2_PKT_FLAG_KEY_PHASE) != 0); 760 } else { 761 ngtcp2_log_info( 762 log, NGTCP2_LOG_EVENT_PKT, 763 "%s pkn=%" PRId64 " dcid=0x%s scid=0x%s version=0x%08x type=%s len=%zu", 764 dir, hd->pkt_num, 765 (const char *)ngtcp2_encode_hex(dcid, hd->dcid.data, hd->dcid.datalen), 766 (const char *)ngtcp2_encode_hex(scid, hd->scid.data, hd->scid.datalen), 767 hd->version, strpkttype(hd), hd->len); 768 } 769} 770 771void ngtcp2_log_rx_pkt_hd(ngtcp2_log *log, const ngtcp2_pkt_hd *hd) { 772 log_pkt_hd(log, hd, "rx"); 773} 774 775void ngtcp2_log_tx_pkt_hd(ngtcp2_log *log, const ngtcp2_pkt_hd *hd) { 776 log_pkt_hd(log, hd, "tx"); 777} 778 779void ngtcp2_log_info(ngtcp2_log *log, ngtcp2_log_event ev, const char *fmt, 780 ...) { 781 va_list ap; 782 int n; 783 char buf[NGTCP2_LOG_BUFLEN]; 784 785 if (!log->log_printf) { 786 return; 787 } 788 789 va_start(ap, fmt); 790 n = vsnprintf(buf, sizeof(buf), fmt, ap); 791 va_end(ap); 792 793 if (n < 0 || (size_t)n >= sizeof(buf)) { 794 return; 795 } 796 797 log->log_printf(log->user_data, (NGTCP2_LOG_HD " %s"), 798 timestamp_cast(log->last_ts - log->ts), log->scid, 799 strevent(ev), buf); 800} 801 802void ngtcp2_log_tx_cancel(ngtcp2_log *log, const ngtcp2_pkt_hd *hd) { 803 ngtcp2_log_info(log, NGTCP2_LOG_EVENT_PKT, 804 "cancel tx pkn=%" PRId64 " type=%s", hd->pkt_num, 805 strpkttype(hd)); 806} 807