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