ssl/quic/quic_trace.c

   1 /*
   2  * Copyright 2023 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 <openssl/bio.h>
  11 #include "../ssl_local.h"
  12 #include "internal/quic_wire_pkt.h"
  13
  14 static const char *packet_type(int type)
  15 {
  16     switch (type) {
  17     case QUIC_PKT_TYPE_INITIAL:
  18         return "Initial";
  19
  20     case QUIC_PKT_TYPE_0RTT:
  21         return "0RTT";
  22
  23     case QUIC_PKT_TYPE_HANDSHAKE:
  24         return "Handshake";
  25
  26     case QUIC_PKT_TYPE_RETRY:
  27         return "Retry";
  28
  29     case QUIC_PKT_TYPE_1RTT:
  30         return "1RTT";
  31
  32     case QUIC_PKT_TYPE_VERSION_NEG:
  33         return "VersionNeg";
  34
  35     default:
  36         return "Unknown";
  37     }
  38 }
  39
  40 /* Print a non-NUL terminated string to BIO */
  41 static void put_str(BIO *bio, char *str, size_t slen)
  42 {
  43     size_t i;
  44
  45     for (i = 0; i < slen; i++)
  46         BIO_printf(bio, "%c", str[i]);
  47 }
  48
  49 static void put_data(BIO *bio, const uint8_t *data, size_t datalen)
  50 {
  51     size_t i;
  52
  53     for (i = 0; i < datalen; i++)
  54         BIO_printf(bio, "%02x", data[i]);
  55 }
  56
  57 static void put_conn_id(BIO *bio, QUIC_CONN_ID *id)
  58 {
  59     if (id->id_len == 0) {
  60         BIO_puts(bio, "<zero length id>");
  61         return;
  62     }
  63
  64     BIO_puts(bio, "0x");
  65     put_data(bio, id->id, id->id_len);
  66 }
  67
  68 static void put_token(BIO *bio, const uint8_t *token, size_t token_len)
  69 {
  70     if (token_len == 0)
  71         BIO_puts(bio, "<zerlo length token>");
  72     else
  73         put_data(bio, token, token_len);
  74 }
  75
  76 static int frame_ack(BIO *bio, PACKET *pkt)
  77 {
  78     OSSL_QUIC_FRAME_ACK ack;
  79     OSSL_QUIC_ACK_RANGE *ack_ranges = NULL;
  80     uint64_t total_ranges = 0;
  81     uint64_t i;
  82
  83     if (!ossl_quic_wire_peek_frame_ack_num_ranges(pkt, &total_ranges)
  84         /* In case sizeof(uint64_t) > sizeof(size_t) */
  85         || total_ranges > SIZE_MAX / sizeof(ack_ranges[0])
  86         || (ack_ranges = OPENSSL_zalloc(sizeof(ack_ranges[0])
  87                                         * (size_t)total_ranges)) == NULL)
  88         return 0;
  89
  90     ack.ack_ranges = ack_ranges;
  91     ack.num_ack_ranges = (size_t)total_ranges;
  92
  93     /* Ack delay exponent is 0, so we can get the raw delay time below */
  94     if (!ossl_quic_wire_decode_frame_ack(pkt, 0, &ack, NULL))
  95         return 0;
  96
  97     BIO_printf(bio, "    Largest acked: %lu\n", ack.ack_ranges[0].end);
  98     BIO_printf(bio, "    Ack delay (raw) %lu\n", ossl_time2ticks(ack.delay_time));
  99     BIO_printf(bio, "    Ack range count: %lu\n", total_ranges - 1);
 100     BIO_printf(bio, "    First ack range: %lu\n",
 101                ack.ack_ranges[0].end - ack.ack_ranges[0].start);
 102     for (i = 1; i < total_ranges; i++) {
 103         BIO_printf(bio, "    Gap: %lu\n",
 104                    ack.ack_ranges[i - 1].start - ack.ack_ranges[i].end - 2);
 105         BIO_printf(bio, "    Ack range len: %lu\n",
 106                    ack.ack_ranges[i].end - ack.ack_ranges[i].start);
 107     }
 108
 109     OPENSSL_free(ack_ranges);
 110     return 1;
 111 }
 112
 113 static int frame_reset_stream(BIO *bio, PACKET *pkt)
 114 {
 115     OSSL_QUIC_FRAME_RESET_STREAM frame_data;
 116
 117     if (!ossl_quic_wire_decode_frame_reset_stream(pkt, &frame_data))
 118         return 0;
 119
 120     BIO_printf(bio, "    Stream id: %lu\n", frame_data.stream_id);
 121     BIO_printf(bio, "    App Protocol Error Code: %lu\n", frame_data.app_error_code);
 122     BIO_printf(bio, "    Final size: %lu\n", frame_data.final_size);
 123
 124     return 1;
 125 }
 126
 127 static int frame_stop_sending(BIO *bio, PACKET *pkt)
 128 {
 129     OSSL_QUIC_FRAME_STOP_SENDING frame_data;
 130
 131     if (!ossl_quic_wire_decode_frame_stop_sending(pkt, &frame_data))
 132         return 0;
 133
 134     BIO_printf(bio, "    Stream id: %lu\n", frame_data.stream_id);
 135     BIO_printf(bio, "    App Protocol Error Code: %lu\n", frame_data.app_error_code);
 136
 137     return 1;
 138 }
 139
 140 static int frame_crypto(BIO *bio, PACKET *pkt)
 141 {
 142     OSSL_QUIC_FRAME_CRYPTO frame_data;
 143
 144     if (!ossl_quic_wire_decode_frame_crypto(pkt, 1, &frame_data))
 145         return 0;
 146
 147     BIO_printf(bio, "    Offset: %lu\n", frame_data.offset);
 148     BIO_printf(bio, "    Len: %lu\n", frame_data.len);
 149
 150     return 1;
 151 }
 152
 153 static int frame_new_token(BIO *bio, PACKET *pkt)
 154 {
 155     const uint8_t *token;
 156     size_t token_len;
 157
 158     if (!ossl_quic_wire_decode_frame_new_token(pkt, &token, &token_len))
 159         return 0;
 160
 161     BIO_puts(bio, "    Token: ");
 162     put_token(bio, token, token_len);
 163     BIO_puts(bio, "\n");
 164
 165     return 1;
 166 }
 167
 168 static int frame_stream(BIO *bio, PACKET *pkt, uint64_t frame_type)
 169 {
 170
 171     OSSL_QUIC_FRAME_STREAM frame_data;
 172
 173     BIO_puts(bio, "Stream");
 174     switch(frame_type) {
 175     case OSSL_QUIC_FRAME_TYPE_STREAM:
 176         BIO_puts(bio, "\n");
 177         break;
 178
 179     case OSSL_QUIC_FRAME_TYPE_STREAM_FIN:
 180         BIO_puts(bio, " (Fin)\n");
 181         break;
 182
 183     case OSSL_QUIC_FRAME_TYPE_STREAM_LEN:
 184         BIO_puts(bio, " (Len)\n");
 185         break;
 186
 187     case OSSL_QUIC_FRAME_TYPE_STREAM_LEN_FIN:
 188         BIO_puts(bio, " (Len, Fin)\n");
 189         break;
 190
 191     case OSSL_QUIC_FRAME_TYPE_STREAM_OFF:
 192         BIO_puts(bio, " (Off)\n");
 193         break;
 194
 195     case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_FIN:
 196         BIO_puts(bio, " (Off, Fin)\n");
 197         break;
 198
 199     case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_LEN:
 200         BIO_puts(bio, " (Off, Len)\n");
 201         break;
 202
 203     case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_LEN_FIN:
 204         BIO_puts(bio, " (Off, Len, Fin)\n");
 205         break;
 206
 207     default:
 208         return 0;
 209     }
 210
 211     if (!ossl_quic_wire_decode_frame_stream(pkt, 1, &frame_data))
 212         return 0;
 213
 214     BIO_printf(bio, "    Stream id: %lu\n", frame_data.stream_id);
 215     BIO_printf(bio, "    Offset: %lu\n", frame_data.offset);
 216     /*
 217      * It would be nice to find a way of passing the implicit length through
 218      * to the msg_callback. But this is not currently possible.
 219      */
 220     if (frame_data.has_explicit_len)
 221         BIO_printf(bio, "    Len: %lu\n", frame_data.len);
 222     else
 223         BIO_puts(bio, "    Len: <implicit length>\n");
 224
 225     return 1;
 226 }
 227
 228 static int frame_max_data(BIO *bio, PACKET *pkt)
 229 {
 230     uint64_t max_data = 0;
 231
 232     if (!ossl_quic_wire_decode_frame_max_data(pkt, &max_data))
 233         return 0;
 234
 235     BIO_printf(bio, "    Max Data: %lu\n", max_data);
 236
 237     return 1;
 238 }
 239
 240 static int frame_max_stream_data(BIO *bio, PACKET *pkt)
 241 {
 242     uint64_t stream_id = 0;
 243     uint64_t max_stream_data = 0;
 244
 245     if (!ossl_quic_wire_decode_frame_max_stream_data(pkt, &stream_id,
 246                                                      &max_stream_data))
 247         return 0;
 248
 249     BIO_printf(bio, "    Max Stream Data: %lu\n", max_stream_data);
 250
 251     return 1;
 252 }
 253
 254 static int frame_max_streams(BIO *bio, PACKET *pkt)
 255 {
 256     uint64_t max_streams = 0;
 257
 258     if (!ossl_quic_wire_decode_frame_max_streams(pkt, &max_streams))
 259         return 0;
 260
 261     BIO_printf(bio, "    Max Streams: %lu\n", max_streams);
 262
 263     return 1;
 264 }
 265
 266 static int frame_data_blocked(BIO *bio, PACKET *pkt)
 267 {
 268     uint64_t max_data = 0;
 269
 270     if (!ossl_quic_wire_decode_frame_data_blocked(pkt, &max_data))
 271         return 0;
 272
 273     BIO_printf(bio, "    Max Data: %lu\n", max_data);
 274
 275     return 1;
 276 }
 277
 278 static int frame_stream_data_blocked(BIO *bio, PACKET *pkt)
 279 {
 280     uint64_t stream_id = 0;
 281     uint64_t max_data = 0;
 282
 283     if (!ossl_quic_wire_decode_frame_stream_data_blocked(pkt, &stream_id,
 284                                                          &max_data))
 285         return 0;
 286
 287     BIO_printf(bio, "    Stream id: %lu\n", stream_id);
 288     BIO_printf(bio, "    Max Data: %lu\n", max_data);
 289
 290     return 1;
 291 }
 292
 293 static int frame_streams_blocked(BIO *bio, PACKET *pkt)
 294 {
 295     uint64_t max_data = 0;
 296
 297     if (!ossl_quic_wire_decode_frame_streams_blocked(pkt, &max_data))
 298         return 0;
 299
 300     BIO_printf(bio, "    Max Data: %lu\n", max_data);
 301
 302     return 1;
 303 }
 304
 305 static int frame_new_conn_id(BIO *bio, PACKET *pkt)
 306 {
 307     OSSL_QUIC_FRAME_NEW_CONN_ID frame_data;
 308
 309     if (!ossl_quic_wire_decode_frame_new_conn_id(pkt, &frame_data))
 310         return 0;
 311
 312     BIO_printf(bio, "    Sequence Number: %lu\n", frame_data.seq_num);
 313     BIO_printf(bio, "    Retire prior to: %lu\n", frame_data.retire_prior_to);
 314     BIO_puts(bio, "    Connection id: ");
 315     put_conn_id(bio, &frame_data.conn_id);
 316     BIO_puts(bio, "\n    Stateless Reset Token: ");
 317     put_data(bio, frame_data.stateless_reset_token, 16);
 318     BIO_puts(bio, "\n");
 319
 320     return 1;
 321 }
 322
 323 static int frame_retire_conn_id(BIO *bio, PACKET *pkt)
 324 {
 325     uint64_t seq_num;
 326
 327     if (!ossl_quic_wire_decode_frame_retire_conn_id(pkt, &seq_num))
 328         return 0;
 329
 330     BIO_printf(bio, "    Sequence Number: %lu\n", seq_num);
 331
 332     return 1;
 333 }
 334
 335 static int frame_path_challenge(BIO *bio, PACKET *pkt)
 336 {
 337     uint64_t data = 0;
 338
 339     if (!ossl_quic_wire_decode_frame_path_challenge(pkt, &data))
 340         return 0;
 341
 342     BIO_printf(bio, "    Data: %016lx\n", data);
 343
 344     return 1;
 345 }
 346
 347 static int frame_path_response(BIO *bio, PACKET *pkt)
 348 {
 349     uint64_t data = 0;
 350
 351     if (!ossl_quic_wire_decode_frame_path_response(pkt, &data))
 352         return 0;
 353
 354     BIO_printf(bio, "    Data: %016lx\n", data);
 355
 356     return 1;
 357 }
 358
 359 static int frame_conn_closed(BIO *bio, PACKET *pkt)
 360 {
 361     OSSL_QUIC_FRAME_CONN_CLOSE frame_data;
 362
 363     if (!ossl_quic_wire_decode_frame_conn_close(pkt, &frame_data))
 364         return 0;
 365
 366     BIO_printf(bio, "    Error Code: %lu\n", frame_data.error_code);
 367     BIO_puts(bio, "    Reason: ");
 368     put_str(bio, frame_data.reason, frame_data.reason_len);
 369     BIO_puts(bio, "\n");
 370
 371     return 1;
 372 }
 373
 374 static int trace_frame_data(BIO *bio, PACKET *pkt)
 375 {
 376     uint64_t frame_type;
 377
 378     if (!ossl_quic_wire_peek_frame_header(pkt, &frame_type))
 379         return 0;
 380
 381     switch (frame_type) {
 382     case OSSL_QUIC_FRAME_TYPE_PING:
 383         BIO_puts(bio, "Ping\n");
 384         if (!ossl_quic_wire_decode_frame_ping(pkt))
 385             return 0;
 386         break;
 387
 388     case OSSL_QUIC_FRAME_TYPE_PADDING:
 389         BIO_puts(bio, "Padding\n");
 390         ossl_quic_wire_decode_padding(pkt);
 391         break;
 392
 393     case OSSL_QUIC_FRAME_TYPE_ACK_WITHOUT_ECN:
 394     case OSSL_QUIC_FRAME_TYPE_ACK_WITH_ECN:
 395         BIO_puts(bio, "Ack ");
 396         if (frame_type == OSSL_QUIC_FRAME_TYPE_ACK_WITH_ECN)
 397             BIO_puts(bio, " (with ECN)\n");
 398         else
 399             BIO_puts(bio, " (without ECN)\n");
 400         if (!frame_ack(bio, pkt))
 401             return 0;
 402         break;
 403
 404     case OSSL_QUIC_FRAME_TYPE_RESET_STREAM:
 405         BIO_puts(bio, "Reset stream\n");
 406         if (!frame_reset_stream(bio, pkt))
 407             return 0;
 408         break;
 409
 410     case OSSL_QUIC_FRAME_TYPE_STOP_SENDING:
 411         BIO_puts(bio, "Stop sending\n");
 412         if (!frame_stop_sending(bio, pkt))
 413             return 0;
 414         break;
 415
 416     case OSSL_QUIC_FRAME_TYPE_CRYPTO:
 417         BIO_puts(bio, "Crypto\n");
 418         if (!frame_crypto(bio, pkt))
 419             return 0;
 420         break;
 421
 422     case OSSL_QUIC_FRAME_TYPE_NEW_TOKEN:
 423         BIO_puts(bio, "New token\n");
 424         if (!frame_new_token(bio, pkt))
 425             return 0;
 426         break;
 427
 428     case OSSL_QUIC_FRAME_TYPE_STREAM:
 429     case OSSL_QUIC_FRAME_TYPE_STREAM_FIN:
 430     case OSSL_QUIC_FRAME_TYPE_STREAM_LEN:
 431     case OSSL_QUIC_FRAME_TYPE_STREAM_LEN_FIN:
 432     case OSSL_QUIC_FRAME_TYPE_STREAM_OFF:
 433     case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_FIN:
 434     case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_LEN:
 435     case OSSL_QUIC_FRAME_TYPE_STREAM_OFF_LEN_FIN:
 436         /* frame_stream() prints the frame type string */
 437         if (!frame_stream(bio, pkt, frame_type))
 438             return 0;
 439         break;
 440
 441     case OSSL_QUIC_FRAME_TYPE_MAX_DATA:
 442         BIO_puts(bio, "Max data\n");
 443         if (!frame_max_data(bio, pkt))
 444             return 0;
 445         break;
 446
 447     case OSSL_QUIC_FRAME_TYPE_MAX_STREAM_DATA:
 448         BIO_puts(bio, "Max stream data\n");
 449         if (!frame_max_stream_data(bio, pkt))
 450             return 0;
 451         break;
 452
 453     case OSSL_QUIC_FRAME_TYPE_MAX_STREAMS_BIDI:
 454     case OSSL_QUIC_FRAME_TYPE_MAX_STREAMS_UNI:
 455         BIO_puts(bio, "Max streams ");
 456         if (frame_type == OSSL_QUIC_FRAME_TYPE_MAX_STREAMS_BIDI)
 457             BIO_puts(bio, " (Bidi)\n");
 458         else
 459             BIO_puts(bio, " (Uni)\n");
 460         if (!frame_max_streams(bio, pkt))
 461             return 0;
 462         break;
 463
 464     case OSSL_QUIC_FRAME_TYPE_DATA_BLOCKED:
 465         BIO_puts(bio, "Data blocked\n");
 466         if (!frame_data_blocked(bio, pkt))
 467             return 0;
 468         break;
 469
 470     case OSSL_QUIC_FRAME_TYPE_STREAM_DATA_BLOCKED:
 471         BIO_puts(bio, "Stream data blocked\n");
 472         if (!frame_stream_data_blocked(bio, pkt))
 473             return 0;
 474         break;
 475
 476     case OSSL_QUIC_FRAME_TYPE_STREAMS_BLOCKED_BIDI:
 477     case OSSL_QUIC_FRAME_TYPE_STREAMS_BLOCKED_UNI:
 478         BIO_puts(bio, "Streams blocked");
 479         if (frame_type == OSSL_QUIC_FRAME_TYPE_STREAMS_BLOCKED_BIDI)
 480             BIO_puts(bio, " (Bidi)\n");
 481         else
 482             BIO_puts(bio, " (Uni)\n");
 483         if (!frame_streams_blocked(bio, pkt))
 484             return 0;
 485         break;
 486
 487     case OSSL_QUIC_FRAME_TYPE_NEW_CONN_ID:
 488         BIO_puts(bio, "New conn id\n");
 489         if (!frame_new_conn_id(bio, pkt))
 490             return 0;
 491         break;
 492
 493     case OSSL_QUIC_FRAME_TYPE_RETIRE_CONN_ID:
 494         BIO_puts(bio, "Retire conn id\n");
 495         if (!frame_retire_conn_id(bio, pkt))
 496             return 0;
 497         break;
 498
 499     case OSSL_QUIC_FRAME_TYPE_PATH_CHALLENGE:
 500         BIO_puts(bio, "Path challenge\n");
 501         if (!frame_path_challenge(bio, pkt))
 502             return 0;
 503         break;
 504
 505     case OSSL_QUIC_FRAME_TYPE_PATH_RESPONSE:
 506         BIO_puts(bio, "Path response\n");
 507         if (!frame_path_response(bio, pkt))
 508             return 0;
 509         break;
 510
 511     case OSSL_QUIC_FRAME_TYPE_CONN_CLOSE_APP:
 512     case OSSL_QUIC_FRAME_TYPE_CONN_CLOSE_TRANSPORT:
 513         BIO_puts(bio, "Connection close");
 514         if (frame_type == OSSL_QUIC_FRAME_TYPE_CONN_CLOSE_APP)
 515             BIO_puts(bio, " (app)\n");
 516         else
 517             BIO_puts(bio, " (transport)\n");
 518         if (!frame_conn_closed(bio, pkt))
 519             return 0;
 520         break;
 521
 522     case OSSL_QUIC_FRAME_TYPE_HANDSHAKE_DONE:
 523         BIO_puts(bio, "Handshake done\n");
 524         if (!ossl_quic_wire_decode_frame_handshake_done(pkt))
 525             return 0;
 526         break;
 527
 528     default:
 529         return 0;
 530     }
 531
 532     if (PACKET_remaining(pkt) != 0)
 533         BIO_puts(bio, "    <unexpected trailing frame data skipped>\n");
 534
 535     return 1;
 536 }
 537
 538 int ossl_quic_trace(int write_p, int version, int content_type,
 539                     const void *buf, size_t msglen, SSL *ssl, void *arg)
 540 {
 541     BIO *bio = arg;
 542     PACKET pkt;
 543
 544     switch (content_type) {
 545     case SSL3_RT_QUIC_DATAGRAM:
 546         BIO_puts(bio, write_p ? "Sent" : "Received");
 547         /*
 548          * Unfortunately there is no way of receiving auxilliary information
 549          * about the datagram through the msg_callback API such as the peer
 550          * address
 551          */
 552         BIO_printf(bio, " Datagram\n  Length: %zu\n", msglen);
 553         break;
 554
 555     case SSL3_RT_QUIC_PACKET:
 556         {
 557             QUIC_PKT_HDR hdr;
 558             size_t i;
 559
 560             if (!PACKET_buf_init(&pkt, buf, msglen))
 561                 return 0;
 562             /* Decode the packet header */
 563             /*
 564              * TODO(QUIC): We need to query the short connection id len here,
 565              *             e.g. via some API SSL_get_short_conn_id_len()
 566              */
 567             if (ossl_quic_wire_decode_pkt_hdr(&pkt, 0, 0, 1, &hdr, NULL) != 1)
 568                 return 0;
 569
 570             BIO_puts(bio, write_p ? "Sent" : "Received");
 571             BIO_puts(bio, " Packet\n");
 572             BIO_printf(bio, "  Packet Type: %s\n", packet_type(hdr.type));
 573             if (hdr.type != QUIC_PKT_TYPE_1RTT)
 574                 BIO_printf(bio, "  Version: 0x%08x\n", hdr.version);
 575             BIO_puts(bio, "  Destination Conn Id: ");
 576             put_conn_id(bio, &hdr.dst_conn_id);
 577             BIO_puts(bio, "\n");
 578             if (hdr.type != QUIC_PKT_TYPE_1RTT) {
 579                 BIO_puts(bio, "  Source Conn Id: ");
 580                 put_conn_id(bio, &hdr.src_conn_id);
 581                 BIO_puts(bio, "\n");
 582             }
 583             BIO_printf(bio, "  Payload length: %zu\n", hdr.len);
 584             if (hdr.type == QUIC_PKT_TYPE_INITIAL) {
 585                 BIO_puts(bio, "  Token: ");
 586                 put_token(bio, hdr.token, hdr.token_len);
 587                 BIO_puts(bio, "\n");
 588             }
 589             if (hdr.type != QUIC_PKT_TYPE_VERSION_NEG
 590                     && hdr.type != QUIC_PKT_TYPE_RETRY) {
 591                 BIO_puts(bio, "  Packet Number: 0x");
 592                 /* Will always be at least 1 byte */
 593                 for (i = 0; i < hdr.pn_len; i++)
 594                     BIO_printf(bio, "%02x", hdr.pn[i]);
 595                 BIO_puts(bio, "\n");
 596             }
 597             break;
 598         }
 599
 600     case SSL3_RT_QUIC_FRAME_PADDING:
 601     case SSL3_RT_QUIC_FRAME_FULL:
 602     case SSL3_RT_QUIC_FRAME_HEADER:
 603         {
 604             BIO_puts(bio, write_p ? "Sent" : "Received");
 605             BIO_puts(bio, " Frame: ");
 606
 607             if (!PACKET_buf_init(&pkt, buf, msglen))
 608                 return 0;
 609             if (!trace_frame_data(bio, &pkt)) {
 610                 BIO_puts(bio, "  <error processing frame data>\n");
 611                 return 0;
 612             }
 613         }
 614         break;
 615
 616     default:
 617         /* Unrecognised content_type. We defer to SSL_trace */
 618         return 0;
 619     }
 620
 621     return 1;
 622 }