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