]> git.ipfire.org Git - thirdparty/openssl.git/blame - ssl/quic/qlog.c
JSON_ENC: Fix unit test for MSVC
[thirdparty/openssl.git] / ssl / quic / qlog.c
CommitLineData
00b27f33
HL
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 "internal/qlog.h"
11#include "internal/json_enc.h"
12#include "internal/common.h"
13#include "internal/cryptlib.h"
ba8b093b 14#include "crypto/ctype.h"
00b27f33 15
ba8b093b
HL
16#define BITS_PER_WORD (sizeof(size_t) * 8)
17#define NUM_ENABLED_W ((QLOG_EVENT_TYPE_NUM + BITS_PER_WORD - 1) / BITS_PER_WORD)
00b27f33
HL
18
19static ossl_unused ossl_inline int bit_get(const size_t *p, uint32_t bit_no)
20{
21 return p[bit_no / BITS_PER_WORD] & (((size_t)1) << (bit_no % BITS_PER_WORD));
22}
23
24static ossl_unused ossl_inline void bit_set(size_t *p, uint32_t bit_no, int enable)
25{
26 size_t mask = (((size_t)1) << (bit_no % BITS_PER_WORD));
27
28 if (enable)
29 p[bit_no / BITS_PER_WORD] |= mask;
30 else
0e6eb431 31 p[bit_no / BITS_PER_WORD] &= ~mask;
00b27f33
HL
32}
33
00b27f33
HL
34struct qlog_st {
35 QLOG_TRACE_INFO info;
36
b3706fd7
HL
37 BIO *bio;
38 size_t enabled[NUM_ENABLED_W];
39 uint32_t event_type;
40 const char *event_cat, *event_name, *event_combined_name;
41 OSSL_TIME event_time, prev_event_time;
42 OSSL_JSON_ENC json;
43 int header_done, first_event_done;
00b27f33
HL
44};
45
46static OSSL_TIME default_now(void *arg)
47{
48 return ossl_time_now();
49}
50
51/*
52 * Construction
53 * ============
54 */
55QLOG *ossl_qlog_new(const QLOG_TRACE_INFO *info)
56{
57 QLOG *qlog = OPENSSL_zalloc(sizeof(QLOG));
58
59 if (qlog == NULL)
60 return NULL;
61
6cb0026c
HL
62 qlog->info.odcid = info->odcid;
63 qlog->info.is_server = info->is_server;
64 qlog->info.now_cb = info->now_cb;
65 qlog->info.now_cb_arg = info->now_cb_arg;
66 qlog->info.override_process_id = info->override_process_id;
00b27f33
HL
67
68 if (info->title != NULL
69 && (qlog->info.title = OPENSSL_strdup(info->title)) == NULL)
26e4bac4 70 goto err;
00b27f33
HL
71
72 if (info->description != NULL
73 && (qlog->info.description = OPENSSL_strdup(info->description)) == NULL)
26e4bac4 74 goto err;
00b27f33
HL
75
76 if (info->group_id != NULL
77 && (qlog->info.group_id = OPENSSL_strdup(info->group_id)) == NULL)
26e4bac4
HL
78 goto err;
79
80 if (info->override_impl_name != NULL
81 && (qlog->info.override_impl_name
82 = OPENSSL_strdup(info->override_impl_name)) == NULL)
83 goto err;
00b27f33 84
b3706fd7
HL
85 if (!ossl_json_init(&qlog->json, NULL,
86 OSSL_JSON_FLAG_IJSON | OSSL_JSON_FLAG_SEQ))
00b27f33
HL
87 goto err;
88
89 if (qlog->info.now_cb == NULL)
90 qlog->info.now_cb = default_now;
91
92 return qlog;
93
94err:
95 if (qlog != NULL) {
96 OPENSSL_free((char *)qlog->info.title);
97 OPENSSL_free((char *)qlog->info.description);
98 OPENSSL_free((char *)qlog->info.group_id);
26e4bac4 99 OPENSSL_free((char *)qlog->info.override_impl_name);
00b27f33
HL
100 OPENSSL_free(qlog);
101 }
102 return NULL;
103}
104
105QLOG *ossl_qlog_new_from_env(const QLOG_TRACE_INFO *info)
106{
29bd1e2d 107 QLOG *qlog = NULL;
00b27f33 108 const char *qlogdir = ossl_safe_getenv("QLOGDIR");
9dcad797 109 const char *qfilter = ossl_safe_getenv("OSSL_QFILTER");
00b27f33
HL
110 char qlogdir_sep, *filename = NULL;
111 size_t i, l, strl;
112
29bd1e2d 113 if (info == NULL || qlogdir == NULL)
00b27f33
HL
114 return NULL;
115
116 l = strlen(qlogdir);
29bd1e2d
HL
117 if (l == 0)
118 return NULL;
119
00b27f33
HL
120 qlogdir_sep = ossl_determine_dirsep(qlogdir);
121
ba8b093b
HL
122 /* dir; [sep]; ODCID; _; strlen("client" / "server"); strlen(".sqlog"); NUL */
123 strl = l + 1 + info->odcid.id_len * 2 + 1 + 6 + 6 + 1;
124 filename = OPENSSL_malloc(strl);
00b27f33
HL
125 if (filename == NULL)
126 return NULL;
127
128 memcpy(filename, qlogdir, l);
129 if (qlogdir_sep != '\0')
130 filename[l++] = qlogdir_sep;
131
132 for (i = 0; i < info->odcid.id_len; ++i)
133 l += sprintf(filename + l, "%02x", info->odcid.id[i]);
134
63aaa51b
HL
135 l += BIO_snprintf(filename + l, strl - l, "_%s.sqlog",
136 info->is_server ? "server" : "client");
00b27f33
HL
137
138 qlog = ossl_qlog_new(info);
29bd1e2d
HL
139 if (qlog == NULL)
140 goto err;
00b27f33 141
29bd1e2d
HL
142 if (!ossl_qlog_set_sink_filename(qlog, filename))
143 goto err;
00b27f33 144
a7066585 145 if (qfilter == NULL || qfilter[0] == '\0')
9dcad797
HL
146 qfilter = "*";
147
148 if (!ossl_qlog_set_filter(qlog, qfilter))
29bd1e2d 149 goto err;
00b27f33
HL
150
151 OPENSSL_free(filename);
152 return qlog;
29bd1e2d
HL
153
154err:
155 OPENSSL_free(filename);
156 ossl_qlog_free(qlog);
157 return NULL;
00b27f33
HL
158}
159
160void ossl_qlog_free(QLOG *qlog)
161{
162 if (qlog == NULL)
163 return;
164
1cc04b77 165 ossl_json_flush_cleanup(&qlog->json);
00b27f33
HL
166 BIO_free_all(qlog->bio);
167 OPENSSL_free((char *)qlog->info.title);
168 OPENSSL_free((char *)qlog->info.description);
169 OPENSSL_free((char *)qlog->info.group_id);
26e4bac4 170 OPENSSL_free((char *)qlog->info.override_impl_name);
00b27f33
HL
171 OPENSSL_free(qlog);
172}
173
174/*
175 * Configuration
176 * =============
177 */
178int ossl_qlog_set_sink_bio(QLOG *qlog, BIO *bio)
179{
180 if (qlog == NULL)
181 return 0;
182
183 ossl_qlog_flush(qlog); /* best effort */
184 BIO_free_all(qlog->bio);
185 qlog->bio = bio;
39b93452 186 ossl_json_set0_sink(&qlog->json, bio);
00b27f33
HL
187 return 1;
188}
189
190#ifndef OPENSSL_NO_STDIO
191
192int ossl_qlog_set_sink_file(QLOG *qlog, FILE *f, int close_flag)
193{
194 BIO *bio;
195
196 if (qlog == NULL)
197 return 0;
198
199 bio = BIO_new_fp(f, BIO_CLOSE);
200 if (bio == NULL)
201 return 0;
202
203 if (!ossl_qlog_set_sink_bio(qlog, bio)) {
204 BIO_free_all(bio);
205 return 0;
206 }
207
208 return 1;
209}
210
211#endif
212
213int ossl_qlog_set_sink_filename(QLOG *qlog, const char *filename)
214{
215 BIO *bio;
216
217 if (qlog == NULL)
218 return 0;
219
220 /*
221 * We supply our own text encoding as JSON requires UTF-8, so disable any
222 * OS-specific processing here.
223 */
224 bio = BIO_new_file(filename, "wb");
225 if (bio == NULL)
226 return 0;
227
228 if (!ossl_qlog_set_sink_bio(qlog, bio)) {
229 BIO_free_all(bio);
230 return 0;
231 }
232
233 return 1;
234}
235
236int ossl_qlog_flush(QLOG *qlog)
237{
238 if (qlog == NULL)
239 return 1;
240
241 return ossl_json_flush(&qlog->json);
242}
243
244int ossl_qlog_set_event_type_enabled(QLOG *qlog, uint32_t event_type,
245 int enabled)
246{
247 if (qlog == NULL || event_type >= QLOG_EVENT_TYPE_NUM)
248 return 0;
249
250 bit_set(qlog->enabled, event_type, enabled);
251 return 1;
252}
253
254int ossl_qlog_enabled(QLOG *qlog, uint32_t event_type)
255{
256 if (qlog == NULL)
257 return 0;
258
6cb0026c 259 return bit_get(qlog->enabled, event_type) != 0;
00b27f33
HL
260}
261
262/*
263 * Event Lifecycle
264 * ===============
265 */
266static void write_str_once(QLOG *qlog, const char *key, char **p)
267{
268 if (*p == NULL)
269 return;
270
271 ossl_json_key(&qlog->json, key);
272 ossl_json_str(&qlog->json, *p);
273
274 OPENSSL_free(*p);
275 *p = NULL;
276}
277
278static void qlog_event_seq_header(QLOG *qlog)
279{
280 if (qlog->header_done)
281 return;
282
283 ossl_json_object_begin(&qlog->json);
284 {
285 ossl_json_key(&qlog->json, "qlog_version");
286 ossl_json_str(&qlog->json, "0.3");
287
288 ossl_json_key(&qlog->json, "qlog_format");
289 ossl_json_str(&qlog->json, "JSON-SEQ");
290
291 write_str_once(qlog, "title", (char **)&qlog->info.title);
292 write_str_once(qlog, "description", (char **)&qlog->info.description);
293
294 ossl_json_key(&qlog->json, "trace");
295 ossl_json_object_begin(&qlog->json);
296 {
297 ossl_json_key(&qlog->json, "common_fields");
298 ossl_json_object_begin(&qlog->json);
299 {
300 ossl_json_key(&qlog->json, "time_format");
301 ossl_json_str(&qlog->json, "delta");
302
303 ossl_json_key(&qlog->json, "protocol_type");
304 ossl_json_array_begin(&qlog->json);
305 {
306 ossl_json_str(&qlog->json, "QUIC");
29bd1e2d 307 } /* protocol_type */
00b27f33
HL
308 ossl_json_array_end(&qlog->json);
309
310 write_str_once(qlog, "group_id", (char **)&qlog->info.group_id);
311
312 ossl_json_key(&qlog->json, "system_info");
313 ossl_json_object_begin(&qlog->json);
314 {
6cb0026c
HL
315 if (qlog->info.override_process_id != 0) {
316 ossl_json_key(&qlog->json, "process_id");
317 ossl_json_u64(&qlog->json, qlog->info.override_process_id);
318 } else {
ba8b093b 319#if defined(OPENSSL_SYS_UNIX) || defined(OPENSSL_SYS_WINDOWS)
6cb0026c
HL
320 ossl_json_key(&qlog->json, "process_id");
321 ossl_json_u64(&qlog->json, (uint64_t)getpid());
ba8b093b 322#endif
6cb0026c 323 }
29bd1e2d 324 } /* system_info */
00b27f33 325 ossl_json_object_end(&qlog->json);
29bd1e2d 326 } /* common_fields */
00b27f33
HL
327 ossl_json_object_end(&qlog->json);
328
329 ossl_json_key(&qlog->json, "vantage_point");
330 ossl_json_object_begin(&qlog->json);
331 {
26e4bac4
HL
332 char buf[128];
333 const char *p = buf;
334
335 if (qlog->info.override_impl_name != NULL) {
336 p = qlog->info.override_impl_name;
337 } else {
c71bde1e
HL
338 BIO_snprintf(buf, sizeof(buf), "OpenSSL/%s (%s)",
339 OpenSSL_version(OPENSSL_FULL_VERSION_STRING),
340 OpenSSL_version(OPENSSL_PLATFORM) + 10);
26e4bac4
HL
341 }
342
00b27f33 343 ossl_json_key(&qlog->json, "type");
f26feac7
HL
344 ossl_json_str(&qlog->json,
345 qlog->info.is_server ? "server" : "client");
26e4bac4
HL
346
347 ossl_json_key(&qlog->json, "name");
348 ossl_json_str(&qlog->json, p);
29bd1e2d 349 } /* vantage_point */
00b27f33 350 ossl_json_object_end(&qlog->json);
29bd1e2d 351 } /* trace */
00b27f33
HL
352 ossl_json_object_end(&qlog->json);
353 }
354 ossl_json_object_end(&qlog->json);
355
356 qlog->header_done = 1;
357}
358
359static void qlog_event_prologue(QLOG *qlog)
360{
361 qlog_event_seq_header(qlog);
362
363 ossl_json_object_begin(&qlog->json);
364
365 ossl_json_key(&qlog->json, "name");
366 ossl_json_str(&qlog->json, qlog->event_combined_name);
367
368 ossl_json_key(&qlog->json, "data");
369 ossl_json_object_begin(&qlog->json);
370}
371
372static void qlog_event_epilogue(QLOG *qlog)
373{
374 ossl_json_object_end(&qlog->json);
375
376 ossl_json_key(&qlog->json, "time");
377 if (!qlog->first_event_done) {
378 ossl_json_u64(&qlog->json, ossl_time2ms(qlog->event_time));
379 qlog->prev_event_time = qlog->event_time;
380 qlog->first_event_done = 1;
381 } else {
382 OSSL_TIME delta = ossl_time_subtract(qlog->event_time,
383 qlog->prev_event_time);
384
385 ossl_json_u64(&qlog->json, ossl_time2ms(delta));
386 qlog->prev_event_time = qlog->event_time;
387 }
388
389 ossl_json_object_end(&qlog->json);
390}
391
392int ossl_qlog_event_try_begin(QLOG *qlog,
393 uint32_t event_type,
394 const char *event_cat,
395 const char *event_name,
396 const char *event_combined_name)
397{
398 if (qlog == NULL)
399 return 0;
400
401 if (!ossl_assert(qlog->event_type == QLOG_EVENT_TYPE_NONE)
402 || !ossl_qlog_enabled(qlog, event_type))
403 return 0;
404
405 qlog->event_type = event_type;
406 qlog->event_cat = event_cat;
407 qlog->event_name = event_name;
408 qlog->event_combined_name = event_combined_name;
409 qlog->event_time = qlog->info.now_cb(qlog->info.now_cb_arg);
410
411 qlog_event_prologue(qlog);
412 return 1;
413}
414
29bd1e2d 415void ossl_qlog_event_end(QLOG *qlog)
00b27f33
HL
416{
417 if (!ossl_assert(qlog != NULL && qlog->event_type != QLOG_EVENT_TYPE_NONE))
418 return;
419
420 qlog_event_epilogue(qlog);
421 qlog->event_type = QLOG_EVENT_TYPE_NONE;
422}
423
00b27f33
HL
424/*
425 * Field Generators
426 * ================
427 */
428void ossl_qlog_group_begin(QLOG *qlog, const char *name)
429{
430 if (name != NULL)
431 ossl_json_key(&qlog->json, name);
432
433 ossl_json_object_begin(&qlog->json);
434}
435
436void ossl_qlog_group_end(QLOG *qlog)
437{
438 ossl_json_object_end(&qlog->json);
439}
440
441void ossl_qlog_array_begin(QLOG *qlog, const char *name)
442{
443 if (name != NULL)
444 ossl_json_key(&qlog->json, name);
445
446 ossl_json_array_begin(&qlog->json);
447}
448
449void ossl_qlog_array_end(QLOG *qlog)
450{
451 ossl_json_array_end(&qlog->json);
452}
453
454void ossl_qlog_override_time(QLOG *qlog, OSSL_TIME event_time)
455{
456 qlog->event_time = event_time;
457}
458
459void ossl_qlog_str(QLOG *qlog, const char *name, const char *value)
460{
461 if (name != NULL)
462 ossl_json_key(&qlog->json, name);
463
464 ossl_json_str(&qlog->json, value);
465}
466
467void ossl_qlog_str_len(QLOG *qlog, const char *name,
468 const char *value, size_t value_len)
469{
470 if (name != NULL)
471 ossl_json_key(&qlog->json, name);
472
473 ossl_json_str_len(&qlog->json, value, value_len);
474}
475
476void ossl_qlog_u64(QLOG *qlog, const char *name, uint64_t value)
477{
478 if (name != NULL)
479 ossl_json_key(&qlog->json, name);
480
481 ossl_json_u64(&qlog->json, value);
482}
483
484void ossl_qlog_i64(QLOG *qlog, const char *name, int64_t value)
485{
486 if (name != NULL)
487 ossl_json_key(&qlog->json, name);
488
489 ossl_json_i64(&qlog->json, value);
490}
491
492void ossl_qlog_bool(QLOG *qlog, const char *name, int value)
493{
494 if (name != NULL)
495 ossl_json_key(&qlog->json, name);
496
497 ossl_json_bool(&qlog->json, value);
498}
499
500void ossl_qlog_bin(QLOG *qlog, const char *name,
501 const void *value, size_t value_len)
502{
503 if (name != NULL)
504 ossl_json_key(&qlog->json, name);
505
506 ossl_json_str_hex(&qlog->json, value, value_len);
507}
508
509/*
510 * Filter Parsing
511 * ==============
512 */
513struct lexer {
514 const char *p, *term_end, *end;
515};
516
517static ossl_inline int is_term_sep_ws(char c)
518{
519 return c == ' ' || c == '\r' || c == '\n' || c == '\t';
520}
521
522static ossl_inline int is_name_char(char c)
523{
ba8b093b 524 return ossl_isalpha(c) || ossl_isdigit(c) || c == '_' || c == '-';
00b27f33
HL
525}
526
527static int lex_init(struct lexer *lex, const char *in, size_t in_len)
528{
529 if (in == NULL)
530 return 0;
531
532 lex->p = in;
533 lex->term_end = in;
534 lex->end = in + in_len;
535 return 1;
536}
537
538static int lex_do(struct lexer *lex)
539{
540 const char *p = lex->term_end, *end = lex->end, *term_end;
541
542 for (; is_term_sep_ws(*p) && p < end; ++p);
543
544 if (p == end) {
545 lex->p = end;
546 lex->term_end = end;
547 return 0;
548 }
549
550 for (term_end = p; !is_term_sep_ws(*term_end) && term_end < end; ++term_end);
551
552 lex->p = p;
553 lex->term_end = term_end;
554 return 1;
555}
556
557static int lex_eot(struct lexer *lex)
558{
559 return lex->p == lex->term_end;
560}
561
562static int lex_peek_char(struct lexer *lex)
563{
564 return lex_eot(lex) ? -1 : *lex->p;
565}
566
567static int lex_skip_char(struct lexer *lex)
568{
569 if (lex_eot(lex))
570 return 0;
571
572 ++lex->p;
573 return 1;
574}
575
576static int lex_match(struct lexer *lex, const char *s, size_t s_len)
577{
578 if ((size_t)(lex->term_end - lex->p) != s_len)
579 return 0;
580
581 if (memcmp(lex->p, s, s_len))
582 return 0;
583
584 return 1;
585}
586
587static void lex_get_rest(struct lexer *lex, const char **str, size_t *str_l)
588{
589 *str = lex->p;
590 *str_l = lex->term_end - lex->p;
591}
592
593static int lex_extract_to(struct lexer *lex, char c,
594 const char **str, size_t *str_l)
595{
596 const char *p = lex->p, *term_end = lex->term_end, *s;
597
598 for (s = p; s < term_end && *s != c; ++s);
599 if (s == term_end)
600 return 0;
601
602 *str = p;
3c067dcb 603 *str_l = s - p;
00b27f33
HL
604 lex->p = ++s;
605 return 1;
606}
607
608static int ossl_unused filter_match_event(const char *cat, size_t cat_l,
609 const char *event, size_t event_l,
610 const char *expect_cat,
611 const char *expect_event)
612{
613 size_t expect_cat_l = strlen(expect_cat);
614 size_t expect_event_l = strlen(expect_event);
615
616 if ((cat != NULL && cat_l != expect_cat_l)
617 || (event != NULL && event_l != expect_event_l)
618 || (cat != NULL && memcmp(cat, expect_cat, expect_cat_l))
619 || (event != NULL && memcmp(event, expect_event, expect_event_l)))
620 return 0;
621
622 return 1;
623}
624
625/*
626 * enabled: event enablement bitmask Array of size NUM_ENABLED_W.
627 * add: 1 to enable an event, 0 to disable.
628 * cat: Category name/length. Not necessarily zero terminated.
629 * NULL to match any.
630 * event: Event name/length. Not necessarily zero terminated.
631 * NULL to match any.
632 */
633static void filter_apply(size_t *enabled, int add,
634 const char *cat, size_t cat_l,
635 const char *event, size_t event_l)
636{
637 /* Find events which match the given filters. */
638# define QLOG_EVENT(e_cat, e_name) \
639 if (filter_match_event(cat, cat_l, event, event_l, \
640 #e_cat, #e_name)) \
641 bit_set(enabled, QLOG_EVENT_TYPE_##e_cat##_##e_name, add);
642# include "internal/qlog_events.h"
643# undef QLOG_EVENT
644}
645
646static int lex_fail(struct lexer *lex, const char *msg)
647{
29bd1e2d 648 /*
ba8b093b
HL
649 * TODO(QLOG FUTURE): Determine how to print log messages about bad filter
650 * strings
29bd1e2d 651 */
00b27f33
HL
652 lex->p = lex->term_end = lex->end;
653 return 0;
654}
655
656static int validate_name(const char **p, size_t *l)
657{
658 const char *p_ = *p;
659 size_t i, l_ = *l;
660
661 if (l_ == 1 && *p_ == '*') {
662 *p = NULL;
663 *l = 0;
664 return 1;
665 }
666
667 if (l_ == 0)
668 return 0;
669
670 for (i = 0; i < l_; ++i)
671 if (!is_name_char(p_[i]))
672 return 0;
673
674 return 1;
675}
676
677int ossl_qlog_set_filter(QLOG *qlog, const char *filter)
678{
679 struct lexer lex = {0};
680 char c;
681 const char *cat, *event;
682 size_t cat_l, event_l, enabled[NUM_ENABLED_W];
683 int add;
684
685 memcpy(enabled, qlog->enabled, sizeof(enabled));
686
687 if (!lex_init(&lex, filter, strlen(filter)))
688 return 0;
689
690 while (lex_do(&lex)) {
691 c = lex_peek_char(&lex);
692 if (c == '+' || c == '-') {
693 add = (c == '+');
694 lex_skip_char(&lex);
695
696 c = lex_peek_char(&lex);
697 if (!is_name_char(c) && c != '*')
698 return lex_fail(&lex, "expected alphanumeric name or '*'"
699 " after +/-");
700 } else if (!is_name_char(c) && c != '*') {
701 return lex_fail(&lex, "expected +/- or alphanumeric name or '*'");
702 } else {
703 add = 1;
704 }
705
706 if (lex_match(&lex, "*", 1)) {
707 filter_apply(enabled, add, NULL, 0, NULL, 0);
708 continue;
709 }
710
711 if (!lex_extract_to(&lex, ':', &cat, &cat_l))
712 return lex_fail(&lex, "expected ':' after category name");
713
714 lex_get_rest(&lex, &event, &event_l);
715 if (!validate_name(&cat, &cat_l))
716 return lex_fail(&lex, "expected alphanumeric category name or '*'");
717 if (!validate_name(&event, &event_l))
718 return lex_fail(&lex, "expected alphanumeric event name or '*'");
719
720 filter_apply(enabled, add, cat, cat_l, event, event_l);
721 }
722
723 memcpy(qlog->enabled, enabled, sizeof(enabled));
724 return 1;
725}