diff --git a/include/picotls.h b/include/picotls.h index d8d61e65..2aaa7e37 100644 --- a/include/picotls.h +++ b/include/picotls.h @@ -1397,20 +1397,22 @@ uint64_t ptls_decode_quicint(const uint8_t **src, const uint8_t *end); ptls_decode_assert_block_close((src), end); \ } while (0) +#if PTLS_HAVE_LOG #define PTLS_LOG__DO_LOG(module, name, conn_state, get_sni, get_sni_arg, add_time, block) \ do { \ - int ptlslog_skip = 0, ptlslog_include_appdata = 0; \ + int ptlslog_include_appdata = 0; \ do { \ - char smallbuf[128]; \ - ptls_buffer_t ptlslogbuf; \ - ptls_log__do_write_start(&logpoint, &ptlslogbuf, smallbuf, sizeof(smallbuf), (add_time)); \ + ptls_log__do_write_start(&logpoint, (add_time)); \ do { \ block \ } while (0); \ - ptlslog_include_appdata = ptls_log__do_write_end(ptlslog_skip ? NULL : &logpoint, (conn_state), (get_sni), \ - (get_sni_arg), &ptlslogbuf, ptlslog_include_appdata); \ - } while (ptlslog_include_appdata); \ + ptlslog_include_appdata = \ + ptls_log__do_write_end(&logpoint, (conn_state), (get_sni), (get_sni_arg), ptlslog_include_appdata); \ + } while (PTLS_UNLIKELY(ptlslog_include_appdata)); \ } while (0) +#else +#define PTLS_LOG__DO_LOG(module, name, conn_state, get_sni, get_sni_arg, add_time, block) /* don't generate code */ +#endif #define PTLS_LOG_DEFINE_POINT(_module, _name, _var) \ static struct st_ptls_log_point_t _var = {.name = PTLS_TO_STR(_module) ":" PTLS_TO_STR(_name)} @@ -1418,7 +1420,7 @@ uint64_t ptls_decode_quicint(const uint8_t **src, const uint8_t *end); #define PTLS_LOG(module, name, block) \ do { \ PTLS_LOG_DEFINE_POINT(module, name, logpoint); \ - if (ptls_log_point_maybe_active(&logpoint) == 0) \ + if (PTLS_LIKELY(ptls_log_point_maybe_active(&logpoint) == 0)) \ break; \ PTLS_LOG__DO_LOG(module, name, NULL, NULL, NULL, 1, {block}); \ } while (0) @@ -1427,12 +1429,12 @@ uint64_t ptls_decode_quicint(const uint8_t **src, const uint8_t *end); do { \ PTLS_LOG_DEFINE_POINT(picotls, name, logpoint); \ uint32_t active = ptls_log_point_maybe_active(&logpoint); \ - if (active == 0) \ + if (PTLS_LIKELY(active == 0)) \ break; \ ptls_t *_tls = (tls); \ ptls_log_conn_state_t *conn_state = ptls_get_log_state(_tls); \ active &= ptls_log_conn_maybe_active(conn_state, (const char *(*)(void *))ptls_get_server_name, _tls); \ - if (active == 0) \ + if (PTLS_LIKELY(active == 0)) \ break; \ PTLS_LOG__DO_LOG(picotls, name, conn_state, (const char *(*)(void *))ptls_get_server_name, _tls, 1, { \ PTLS_LOG_ELEMENT_PTR(tls, _tls); \ @@ -1442,94 +1444,50 @@ uint64_t ptls_decode_quicint(const uint8_t **src, const uint8_t *end); }); \ } while (0) +#define PTLS_LOG__ELEMENT_PREFIX_CORE(lit) ",\"" lit "\":" +#define PTLS_LOG__ELEMENT_PREFIX(lit) PTLS_LOG__ELEMENT_PREFIX_CORE(lit), sizeof(PTLS_LOG__ELEMENT_PREFIX_CORE(lit)) - 1 #define PTLS_LOG_ELEMENT_SAFESTR(name, value) \ do { \ - PTLS_LOG__DO_PUSH_SAFESTR(",\"" PTLS_TO_STR(name) "\":\""); \ - PTLS_LOG__DO_PUSH_SAFESTR(value); \ - PTLS_LOG__DO_PUSH_SAFESTR("\""); \ + const char *value_ = (value); \ + ptls_log__do_push_element_safestr(PTLS_LOG__ELEMENT_PREFIX(PTLS_TO_STR(name)), (value_), strlen(value_)); \ } while (0) #define PTLS_LOG_ELEMENT_UNSAFESTR(name, value, value_len) \ - do { \ - PTLS_LOG__DO_PUSH_SAFESTR(",\"" PTLS_TO_STR(name) "\":\""); \ - PTLS_LOG__DO_PUSH_UNSAFESTR(value, value_len); \ - PTLS_LOG__DO_PUSH_SAFESTR("\""); \ - } while (0) + ptls_log__do_push_element_unsafestr(PTLS_LOG__ELEMENT_PREFIX(PTLS_TO_STR(name)), (value), (value_len)) #define PTLS_LOG_ELEMENT_HEXDUMP(name, value, value_len) \ - do { \ - PTLS_LOG__DO_PUSH_SAFESTR(",\"" PTLS_TO_STR(name) "\":\""); \ - PTLS_LOG__DO_PUSH_HEXDUMP(value, value_len); \ - PTLS_LOG__DO_PUSH_SAFESTR("\""); \ - } while (0) + ptls_log__do_push_element_hexdump(PTLS_LOG__ELEMENT_PREFIX(PTLS_TO_STR(name)), (value), (value_len)) #define PTLS_LOG_ELEMENT_PTR(name, value) PTLS_LOG_ELEMENT_UNSIGNED(name, (uint64_t)(value)) #define PTLS_LOG_ELEMENT_SIGNED(name, value) \ do { \ - PTLS_LOG__DO_PUSH_SAFESTR(",\"" PTLS_TO_STR(name) "\":"); \ - PTLS_LOG__DO_PUSH_SIGNED(value); \ - } while (0) -#define PTLS_LOG_ELEMENT__DO_UNSIGNED(name, suffix, value) \ - do { \ - PTLS_LOG__DO_PUSH_SAFESTR(",\"" PTLS_TO_STR(name) suffix "\":"); \ - PTLS_LOG__DO_PUSH_UNSIGNED(value); \ + if (sizeof(value) <= sizeof(int32_t)) { \ + ptls_log__do_push_element_signed32(PTLS_LOG__ELEMENT_PREFIX(PTLS_TO_STR(name)), (value)); \ + } else { \ + ptls_log__do_push_element_signed64(PTLS_LOG__ELEMENT_PREFIX(PTLS_TO_STR(name)), (value)); \ + } \ } while (0) -#define PTLS_LOG_ELEMENT_UNSIGNED(name, value) PTLS_LOG_ELEMENT__DO_UNSIGNED(name, "", value) -#define PTLS_LOG_ELEMENT_BOOL(name, value) \ +#define PTLS_LOG__DO_ELEMENT_UNSIGNED(lit, value) \ do { \ - PTLS_LOG__DO_PUSH_SAFESTR(",\"" PTLS_TO_STR(name) "\":"); \ - PTLS_LOG__DO_PUSH_SAFESTR(value ? "true" : "false"); \ + if (sizeof(value) <= sizeof(uint32_t)) { \ + ptls_log__do_push_element_unsigned32(PTLS_LOG__ELEMENT_PREFIX(lit), (value)); \ + } else { \ + ptls_log__do_push_element_unsigned64(PTLS_LOG__ELEMENT_PREFIX(lit), (value)); \ + } \ } while (0) - +#define PTLS_LOG_ELEMENT_UNSIGNED(name, value) PTLS_LOG__DO_ELEMENT_UNSIGNED(PTLS_TO_STR(name), (value)) +#define PTLS_LOG_ELEMENT_BOOL(name, value) ptls_log__do_push_element_bool(PTLS_LOG__ELEMENT_PREFIX(PTLS_TO_STR(name)), (value)) #define PTLS_LOG_APPDATA_ELEMENT_UNSAFESTR(name, value, value_len) \ do { \ - size_t _len = (value_len); \ - if (ptlslog_include_appdata) \ - PTLS_LOG_ELEMENT_UNSAFESTR(name, value, _len); \ - PTLS_LOG_ELEMENT__DO_UNSIGNED(name, "_len", _len); \ - } while (0) -#define PTLS_LOG_APPDATA_ELEMENT_HEXDUMP(name, value, value_len) \ - do { \ - size_t _len = (value_len); \ - if (ptlslog_include_appdata) \ - PTLS_LOG_ELEMENT_HEXDUMP(name, value, _len); \ - PTLS_LOG_ELEMENT__DO_UNSIGNED(name, "_len", _len); \ - } while (0) - -#define PTLS_LOG__DO_PUSH_SAFESTR(v) \ - do { \ - if (PTLS_UNLIKELY(!ptlslog_skip && !ptls_log__do_push_safestr(&ptlslogbuf, (v)))) \ - ptlslog_skip = 1; \ - } while (0) -#define PTLS_LOG__DO_PUSH_UNSAFESTR(v, l) \ - do { \ - if (PTLS_UNLIKELY(!ptlslog_skip && !ptls_log__do_push_unsafestr(&ptlslogbuf, (v), (l)))) \ - ptlslog_skip = 1; \ - } while (0) -#define PTLS_LOG__DO_PUSH_HEXDUMP(v, l) \ - do { \ - if (PTLS_UNLIKELY(!ptlslog_skip && !ptls_log__do_push_hexdump(&ptlslogbuf, (v), (l)))) \ - ptlslog_skip = 1; \ - } while (0) -#define PTLS_LOG__DO_PUSH_SIGNED(v) \ - do { \ - if (PTLS_UNLIKELY(!ptlslog_skip)) { \ - if (sizeof(v) <= sizeof(int32_t)) { \ - if (PTLS_UNLIKELY(!ptls_log__do_push_signed32(&ptlslogbuf, (v)))) \ - ptlslog_skip = 1; \ - } else { \ - if (PTLS_UNLIKELY(!ptls_log__do_push_signed64(&ptlslogbuf, (v)))) \ - ptlslog_skip = 1; \ - } \ + if (ptlslog_include_appdata) { \ + PTLS_LOG_ELEMENT_UNSAFESTR(name, value, value_len); \ + } else { \ + PTLS_LOG__DO_ELEMENT_UNSIGNED(PTLS_TO_STR(name) "_len", value_len); \ } \ } while (0) -#define PTLS_LOG__DO_PUSH_UNSIGNED(v) \ +#define PTLS_LOG_APPDATA_ELEMENT_HEXDUMP(name, value, value_len) \ do { \ - if (PTLS_UNLIKELY(!ptlslog_skip)) { \ - if (sizeof(v) <= sizeof(uint32_t)) { \ - if (PTLS_UNLIKELY(!ptls_log__do_push_unsigned32(&ptlslogbuf, (uint32_t)(v)))) \ - ptlslog_skip = 1; \ - } else { \ - if (PTLS_UNLIKELY(!ptls_log__do_push_unsigned64(&ptlslogbuf, (v)))) \ - ptlslog_skip = 1; \ - } \ + if (ptlslog_include_appdata) { \ + PTLS_LOG_ELEMENT_HEXDUMP(name, value, value_len); \ + } else { \ + PTLS_LOG__DO_ELEMENT_UNSIGNED(PTLS_TO_STR(name) "_len", value_len); \ } \ } while (0) @@ -1628,18 +1586,21 @@ int ptls_log_add_fd(int fd, float sample_ratio, const char *points, const char * void ptls_log__recalc_point(int caller_locked, struct st_ptls_log_point_t *point); void ptls_log__recalc_conn(int caller_locked, struct st_ptls_log_conn_state_t *conn, const char *(*get_sni)(void *), void *get_sni_arg); -static int ptls_log__do_push_safestr(ptls_buffer_t *buf, const char *s); -int ptls_log__do_push_unsafestr(ptls_buffer_t *buf, const char *s, size_t l); -int ptls_log__do_push_hexdump(ptls_buffer_t *buf, const void *s, size_t l); -int ptls_log__do_pushv(ptls_buffer_t *buf, const void *p, size_t l); -int ptls_log__do_push_signed32(ptls_buffer_t *buf, int32_t v); -int ptls_log__do_push_signed64(ptls_buffer_t *buf, int64_t v); -int ptls_log__do_push_unsigned32(ptls_buffer_t *buf, uint32_t v); -int ptls_log__do_push_unsigned64(ptls_buffer_t *buf, uint64_t v); -void ptls_log__do_write_start(struct st_ptls_log_point_t *point, ptls_buffer_t *buf, void *smallbuf, size_t smallbufsize, - int add_time); +void ptls_log__do_push_element_safestr(const char *prefix, size_t prefix_len, const char *s, size_t l); +void ptls_log__do_push_element_unsafestr(const char *prefix, size_t prefix_len, const char *s, size_t l); +void ptls_log__do_push_element_hexdump(const char *prefix, size_t prefix_len, const void *s, size_t l); +void ptls_log__do_push_element_signed32(const char *prefix, size_t prefix_len, int32_t v); +void ptls_log__do_push_element_signed64(const char *prefix, size_t prefix_len, int64_t v); +void ptls_log__do_push_element_unsigned32(const char *prefix, size_t prefix_len, uint32_t v); +void ptls_log__do_push_element_unsigned64(const char *prefix, size_t prefix_len, uint64_t v); +void ptls_log__do_push_element_bool(const char *prefix, size_t prefix_len, int v); +void ptls_log__do_push_appdata_element_unsafestr(int includes_appdata, const char *prefix, size_t prefix_len, const char *s, + size_t l); +void ptls_log__do_push_appdata_element_hexdump(int includes_appdata, const char *prefix, size_t prefix_len, const void *s, + size_t l); +void ptls_log__do_write_start(struct st_ptls_log_point_t *point, int add_time); int ptls_log__do_write_end(struct st_ptls_log_point_t *point, struct st_ptls_log_conn_state_t *conn, const char *(*get_sni)(void *), - void *get_sni_arg, ptls_buffer_t *buf, int includes_appdata); + void *get_sni_arg, int includes_appdata); /** * create a client object to handle new TLS connection @@ -2002,11 +1963,13 @@ static void ptls_hash_clone_memcpy(void *dst, const void *src, size_t size); inline uint32_t ptls_log_point_maybe_active(struct st_ptls_log_point_t *point) { - if (!PTLS_HAVE_LOG) - return 0; +#if PTLS_HAVE_LOG if (PTLS_UNLIKELY(point->state.generation != ptls_log._generation)) ptls_log__recalc_point(0, point); return point->state.active_conns; +#else + return 0; +#endif } inline void ptls_log_recalc_conn_state(ptls_log_conn_state_t *state) @@ -2016,16 +1979,13 @@ inline void ptls_log_recalc_conn_state(ptls_log_conn_state_t *state) inline uint32_t ptls_log_conn_maybe_active(ptls_log_conn_state_t *conn, const char *(*get_sni)(void *), void *get_sni_arg) { - if (!PTLS_HAVE_LOG) - return 0; +#if PTLS_HAVE_LOG if (PTLS_UNLIKELY(conn->state.generation != ptls_log._generation)) ptls_log__recalc_conn(0, conn, get_sni, get_sni_arg); return conn->state.active_conns; -} - -inline int ptls_log__do_push_safestr(ptls_buffer_t *buf, const char *s) -{ - return ptls_log__do_pushv(buf, s, strlen(s)); +#else + return 0; +#endif } inline ptls_t *ptls_new(ptls_context_t *ctx, int is_server) diff --git a/lib/picotls.c b/lib/picotls.c index da909eaf..8bfa63c7 100644 --- a/lib/picotls.c +++ b/lib/picotls.c @@ -23,6 +23,7 @@ #include "wincompat.h" #endif #include +#include #include #include #include @@ -6774,69 +6775,6 @@ void ptls_build_v4_mapped_v6_address(struct in6_addr *v6, const struct in_addr * memcpy(&v6->s6_addr[12], &v4->s_addr, 4); } -int ptls_log__do_pushv(ptls_buffer_t *buf, const void *p, size_t l) -{ - if (ptls_buffer_reserve(buf, l) != 0) - return 0; - - memcpy(buf->base + buf->off, p, l); - buf->off += l; - return 1; -} - -int ptls_log__do_push_unsafestr(ptls_buffer_t *buf, const char *s, size_t l) -{ - if (ptls_buffer_reserve(buf, l * (sizeof("\\uXXXX") - 1) + 1) != 0) - return 0; - - buf->off = (uint8_t *)ptls_jsonescape((char *)(buf->base + buf->off), s, l) - buf->base; - - return 1; -} - -int ptls_log__do_push_hexdump(ptls_buffer_t *buf, const void *s, size_t l) -{ - if (ptls_buffer_reserve(buf, l * 2 + 1) != 0) - return 0; - - ptls_hexdump((char *)(buf->base + buf->off), s, l); - buf->off += l * 2; - - return 1; -} - -int ptls_log__do_push_signed32(ptls_buffer_t *buf, int32_t v) -{ - /* TODO optimize */ - char s[sizeof("-2147483648")]; - int len = snprintf(s, sizeof(s), "%" PRId32, v); - return ptls_log__do_pushv(buf, s, (size_t)len); -} - -int ptls_log__do_push_signed64(ptls_buffer_t *buf, int64_t v) -{ - /* TODO optimize */ - char s[sizeof("-9223372036854775808")]; - int len = snprintf(s, sizeof(s), "%" PRId64, v); - return ptls_log__do_pushv(buf, s, (size_t)len); -} - -int ptls_log__do_push_unsigned32(ptls_buffer_t *buf, uint32_t v) -{ - /* TODO optimize */ - char s[sizeof("4294967295")]; - int len = snprintf(s, sizeof(s), "%" PRIu32, v); - return ptls_log__do_pushv(buf, s, (size_t)len); -} - -int ptls_log__do_push_unsigned64(ptls_buffer_t *buf, uint64_t v) -{ - /* TODO optimize */ - char s[sizeof("18446744073709551615")]; - int len = snprintf(s, sizeof(s), "%" PRIu64, v); - return ptls_log__do_pushv(buf, s, (size_t)len); -} - struct st_ptls_log_t ptls_log = { .dummy_conn_state = {.random_ = 1 /* never log */}, ._generation = 1, /* starts from 1 so that recalc can be forced by setting to zero (i.e., the initial) */ @@ -6889,6 +6827,15 @@ static struct { pthread_mutex_t mutex; } logctx = {.mutex = PTHREAD_MUTEX_INITIALIZER}; +static PTLS_THREADLOCAL struct { + ptls_buffer_t buf; /* buf.base == NULL upon failre */ + char smallbuf[128]; + struct { + char buf[sizeof(",\"tid\":-9223372036854775808")]; + size_t len; + } tid; +} logbuf; + static void close_log_fd(size_t slot) { assert(logctx.conns[slot].fd >= 0 && logctx.conns[slot].points != NULL); @@ -6957,31 +6904,8 @@ static int is_in_addresslist(const struct in6_addr *list, const struct in6_addr #undef IS_EQUAL } -#endif - -void ptls_log_init_conn_state(ptls_log_conn_state_t *state, void (*random_bytes)(void *, size_t)) -{ - uint32_t r; - random_bytes(&r, sizeof(r)); - - *state = (ptls_log_conn_state_t){ - .random_ = (float)r / ((uint64_t)UINT32_MAX + 1), /* [0..1), so that any(r) < sample_ratio where sample_ratio is [0..1] */ - .address = in6addr_any, - }; -} - -size_t ptls_log_num_lost(void) -{ -#if PTLS_HAVE_LOG - return logctx.num_lost; -#else - return 0; -#endif -} - void ptls_log__recalc_point(int caller_locked, struct st_ptls_log_point_t *point) { -#if PTLS_HAVE_LOG if (!caller_locked) pthread_mutex_lock(&logctx.mutex); @@ -6997,13 +6921,11 @@ void ptls_log__recalc_point(int caller_locked, struct st_ptls_log_point_t *point if (!caller_locked) pthread_mutex_unlock(&logctx.mutex); -#endif } void ptls_log__recalc_conn(int caller_locked, struct st_ptls_log_conn_state_t *conn, const char *(*get_sni)(void *), void *get_sni_arg) { -#if PTLS_HAVE_LOG if (!caller_locked) pthread_mutex_lock(&logctx.mutex); @@ -7023,159 +6945,155 @@ void ptls_log__recalc_conn(int caller_locked, struct st_ptls_log_conn_state_t *c if (!caller_locked) pthread_mutex_unlock(&logctx.mutex); -#endif } -int ptls_log_add_fd(int fd, float sample_ratio, const char *_points, const char *_snis, const char *_addresses, int appdata) +static int expand_logbuf_or_invalidate(const char *prefix, size_t prefix_len, size_t capacity) { -#if PTLS_HAVE_LOG + if (logbuf.buf.base == NULL) + return 0; - char *points = NULL, *snis = NULL; - struct in6_addr *addresses = NULL; - int ret; + if (ptls_buffer_reserve(&logbuf.buf, prefix_len + capacity) != 0) { + ptls_buffer_dispose(&logbuf.buf); + assert(logbuf.buf.base == NULL); + return 0; + } - pthread_mutex_lock(&logctx.mutex); + memcpy(logbuf.buf.base + logbuf.buf.off, prefix, prefix_len); + logbuf.buf.off += prefix_len; - if ((points = duplicate_stringlist(_points)) == NULL) { - ret = PTLS_ERROR_NO_MEMORY; - goto Exit; - } - if ((snis = duplicate_stringlist(_snis)) == NULL) { - ret = PTLS_ERROR_NO_MEMORY; - goto Exit; + return 1; +} + +__attribute__((format(printf, 4, 5))) static void pushf_logbuf_or_invalidate(const char *prefix, size_t prefix_len, size_t capacity, + const char *fmt, ...) +{ + if (!expand_logbuf_or_invalidate(prefix, prefix_len, capacity)) + return; + + va_list args; + va_start(args, fmt); + int l = vsnprintf((char *)logbuf.buf.base + logbuf.buf.off, logbuf.buf.capacity - logbuf.buf.off, fmt, args); + va_end(args); + + assert(l < logbuf.buf.capacity - logbuf.buf.off && "insufficent capacity"); + logbuf.buf.off += l; +} + +void ptls_log__do_push_element_safestr(const char *prefix, size_t prefix_len, const char *s, size_t l) +{ + if (expand_logbuf_or_invalidate(prefix, prefix_len, l + 2)) { + logbuf.buf.base[logbuf.buf.off++] = '"'; + memcpy(logbuf.buf.base + logbuf.buf.off, s, l); + logbuf.buf.off += l; + logbuf.buf.base[logbuf.buf.off++] = '"'; } - { - size_t num_addresses = 0; - for (const char *input = _addresses; input != NULL && *input != '\0'; input += strlen(input) + 1) - ++num_addresses; - if ((addresses = malloc(sizeof(*addresses) * (num_addresses + 1))) == NULL) { - ret = PTLS_ERROR_NO_MEMORY; - goto Exit; - } - size_t index = 0; - for (const char *input = _addresses; input != NULL && *input != '\0'; input += strlen(input) + 1) { - /* note: for consistency to the handling of points, erroneous input is ignored. V4 addresses will use the mapped form - * (::ffff:192.0.2.1) */ - if (!inet_pton(AF_INET6, input, &addresses[index])) { - struct in_addr v4; - if (!inet_pton(AF_INET, input, &v4)) - continue; - ptls_build_v4_mapped_v6_address(&addresses[index], &v4); - } - if (memcmp(&addresses[index], &in6addr_any, sizeof(struct in6_addr)) == 0) - continue; - ++index; - } - addresses[index] = in6addr_any; +} + +void ptls_log__do_push_element_unsafestr(const char *prefix, size_t prefix_len, const char *s, size_t l) +{ + if (expand_logbuf_or_invalidate(prefix, prefix_len, l * (sizeof("\\uXXXX") - 1) + 2)) { + logbuf.buf.base[logbuf.buf.off++] = '"'; + logbuf.buf.off = (uint8_t *)ptls_jsonescape((char *)logbuf.buf.base + logbuf.buf.off, s, l) - logbuf.buf.base; + logbuf.buf.base[logbuf.buf.off++] = '"'; } +} - /* find slot, or return if not available */ - size_t slot_index; - for (slot_index = 0; slot_index < PTLS_ELEMENTSOF(logctx.conns); ++slot_index) - if (logctx.conns[slot_index].points == NULL) - break; - if (slot_index == PTLS_ELEMENTSOF(logctx.conns)) { - ret = PTLS_ERROR_NO_MEMORY; - goto Exit; +void ptls_log__do_push_element_hexdump(const char *prefix, size_t prefix_len, const void *s, size_t l) +{ + if (expand_logbuf_or_invalidate(prefix, prefix_len, l * 2 + 2)) { + logbuf.buf.base[logbuf.buf.off++] = '"'; + ptls_hexdump((char *)logbuf.buf.base + logbuf.buf.off, s, l); + logbuf.buf.off += l * 2; + logbuf.buf.base[logbuf.buf.off++] = '"'; } +} - /* setup the slot */ - logctx.conns[slot_index].fd = fd; - logctx.conns[slot_index].points = points; - logctx.conns[slot_index].snis = snis; - logctx.conns[slot_index].addresses = addresses; - logctx.conns[slot_index].sample_ratio = sample_ratio; - logctx.conns[slot_index].appdata = appdata; - ++ptls_log._generation; +void ptls_log__do_push_element_signed32(const char *prefix, size_t prefix_len, int32_t v) +{ + pushf_logbuf_or_invalidate(prefix, prefix_len, sizeof("-2147483648"), "%" PRId32, v); +} - ret = 0; /* success */ +void ptls_log__do_push_element_signed64(const char *prefix, size_t prefix_len, int64_t v) +{ + pushf_logbuf_or_invalidate(prefix, prefix_len, sizeof("-9223372036854775808"), "%" PRId64, v); +} -Exit: - pthread_mutex_unlock(&logctx.mutex); - if (ret != 0) { - free(points); - free(snis); - free(addresses); - } - return ret; +void ptls_log__do_push_element_unsigned32(const char *prefix, size_t prefix_len, uint32_t v) +{ + pushf_logbuf_or_invalidate(prefix, prefix_len, sizeof("4294967295"), "%" PRIu32, v); +} -#else - return PTLS_ERROR_NOT_AVAILABLE; -#endif +void ptls_log__do_push_element_unsigned64(const char *prefix, size_t prefix_len, uint64_t v) +{ + pushf_logbuf_or_invalidate(prefix, prefix_len, sizeof("18446744073709551615"), "%" PRIu64, v); } -void ptls_log__do_write_start(struct st_ptls_log_point_t *point, ptls_buffer_t *buf, void *smallbuf, size_t smallbufsize, - int add_time) +void ptls_log__do_push_element_bool(const char *prefix, size_t prefix_len, int v) { - ptls_buffer_init(buf, smallbuf, smallbufsize); + if (expand_logbuf_or_invalidate(prefix, prefix_len, 5)) { + if (v) { + memcpy(logbuf.buf.base + logbuf.buf.off, "true", 4); + logbuf.buf.off += 4; + } else { + memcpy(logbuf.buf.base + logbuf.buf.off, "false", 5); + logbuf.buf.off += 5; + } + } +} + +void ptls_log__do_write_start(struct st_ptls_log_point_t *point, int add_time) +{ + assert(logbuf.buf.base == NULL); + ptls_buffer_init(&logbuf.buf, logbuf.smallbuf, sizeof(logbuf.smallbuf)); /* add module and type name */ const char *colon_at = strchr(point->name, ':'); - int written = snprintf((char *)buf->base, buf->capacity, "{\"module\":\"%.*s\",\"type\":\"%s\"", (int)(colon_at - point->name), - point->name, colon_at + 1); + int written = snprintf((char *)logbuf.buf.base, logbuf.buf.capacity, "{\"module\":\"%.*s\",\"type\":\"%s\"", + (int)(colon_at - point->name), point->name, colon_at + 1); -#if defined(__linux__) || defined(__APPLE__) /* obtain and stringify thread id once */ - static PTLS_THREADLOCAL struct { - char buf[sizeof(",\"tid\":-9223372036854775808")]; - size_t len; - } tid; - if (tid.len == 0) { - static pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER; - pthread_mutex_lock(&mutex); - if (tid.len == 0) { + if (logbuf.tid.len == 0) { #if defined(__linux__) - int l = sprintf(tid.buf, ",\"tid\":%" PRId64, (int64_t)syscall(SYS_gettid)); + logbuf.tid.len = sprintf(logbuf.tid.buf, ",\"tid\":%" PRId64, (int64_t)syscall(SYS_gettid)); #elif defined(__APPLE__) - uint64_t t = 0; - (void)pthread_threadid_np(NULL, &t); - int l = sprintf(tid.buf, ",\"tid\":%" PRIu64, t); + uint64_t t = 0; + (void)pthread_threadid_np(NULL, &t); + logbuf.tid.len = sprintf(logbuf.tid.buf, ",\"tid\":%" PRIu64, t); #else -#error "unexpected platform" + /* other platforms: skip emitting tid, by keeping logbuf.tid.len == 0 */ #endif - __sync_synchronize(); - tid.len = (size_t)l; - } - pthread_mutex_unlock(&mutex); } /* append tid */ - assert(written > 0 && written + tid.len < buf->capacity); - memcpy((char *)buf->base + written, tid.buf, tid.len + 1); - written += tid.len; -#endif + assert(written > 0 && written + logbuf.tid.len < logbuf.buf.capacity); + memcpy((char *)logbuf.buf.base + written, logbuf.tid.buf, logbuf.tid.len + 1); + written += logbuf.tid.len; /* append time if requested */ if (add_time) { struct timeval tv; gettimeofday(&tv, NULL); - written += snprintf((char *)buf->base + written, buf->capacity - written, ",\"time\":%" PRIu64, + written += snprintf((char *)logbuf.buf.base + written, logbuf.buf.capacity - written, ",\"time\":%" PRIu64, (uint64_t)tv.tv_sec * 1000 + tv.tv_usec / 1000); } - assert(written > 0 && written < buf->capacity && "caller MUST provide smallbuf suffient to emit the prefix"); + assert(written > 0 && written < logbuf.buf.capacity && "caller MUST provide smallbuf suffient to emit the prefix"); - buf->off = (size_t)written; + logbuf.buf.off = (size_t)written; } int ptls_log__do_write_end(struct st_ptls_log_point_t *point, struct st_ptls_log_conn_state_t *conn, const char *(*get_sni)(void *), - void *get_sni_arg, ptls_buffer_t *buf, int includes_appdata) + void *get_sni_arg, int includes_appdata) { - int needs_appdata = 0; - -#if PTLS_HAVE_LOG - uint32_t active; + if (!expand_logbuf_or_invalidate("}\n", 2, 0)) + return 0; - /* point == NULL indicates skip */ - if (point == NULL || ptls_buffer_reserve(buf, 2) != 0) - goto Exit; - buf->base[buf->off++] = '}'; - buf->base[buf->off++] = '\n'; + int needs_appdata = 0; pthread_mutex_lock(&logctx.mutex); /* calc the active conn bits, updating stale information if necessary */ if (point->state.generation != ptls_log._generation) ptls_log__recalc_point(1, point); - active = point->state.active_conns; + uint32_t active = point->state.active_conns; if (conn != NULL && conn->state.generation != ptls_log._generation) { ptls_log__recalc_conn(1, conn, get_sni, get_sni_arg); active &= conn->state.active_conns; @@ -7196,9 +7114,9 @@ int ptls_log__do_write_end(struct st_ptls_log_point_t *point, struct st_ptls_log /* write */ ssize_t wret; - while ((wret = write(logctx.conns[slot].fd, buf->base, buf->off)) == -1 && errno == EINTR) + while ((wret = write(logctx.conns[slot].fd, logbuf.buf.base, logbuf.buf.off)) == -1 && errno == EINTR) ; - if (wret == buf->off) { + if (wret == logbuf.buf.off) { /* success */ } else if (wret > 0 || (wret == -1 && (errno == EAGAIN || errno == EWOULDBLOCK))) { /* partial write or buffer full */ @@ -7213,9 +7131,108 @@ int ptls_log__do_write_end(struct st_ptls_log_point_t *point, struct st_ptls_log if (includes_appdata) assert(!needs_appdata); + + ptls_buffer_dispose(&logbuf.buf); + assert(logbuf.buf.base == NULL); + return needs_appdata; +} + +#endif + +void ptls_log_init_conn_state(ptls_log_conn_state_t *state, void (*random_bytes)(void *, size_t)) +{ + uint32_t r; + random_bytes(&r, sizeof(r)); + + *state = (ptls_log_conn_state_t){ + .random_ = (float)r / ((uint64_t)UINT32_MAX + 1), /* [0..1), so that any(r) < sample_ratio where sample_ratio is [0..1] */ + .address = in6addr_any, + }; +} + +size_t ptls_log_num_lost(void) +{ +#if PTLS_HAVE_LOG + return logctx.num_lost; +#else + return 0; #endif +} + +int ptls_log_add_fd(int fd, float sample_ratio, const char *_points, const char *_snis, const char *_addresses, int appdata) +{ +#if PTLS_HAVE_LOG + + char *points = NULL, *snis = NULL; + struct in6_addr *addresses = NULL; + int ret; + + pthread_mutex_lock(&logctx.mutex); + + if ((points = duplicate_stringlist(_points)) == NULL) { + ret = PTLS_ERROR_NO_MEMORY; + goto Exit; + } + if ((snis = duplicate_stringlist(_snis)) == NULL) { + ret = PTLS_ERROR_NO_MEMORY; + goto Exit; + } + { + size_t num_addresses = 0; + for (const char *input = _addresses; input != NULL && *input != '\0'; input += strlen(input) + 1) + ++num_addresses; + if ((addresses = malloc(sizeof(*addresses) * (num_addresses + 1))) == NULL) { + ret = PTLS_ERROR_NO_MEMORY; + goto Exit; + } + size_t index = 0; + for (const char *input = _addresses; input != NULL && *input != '\0'; input += strlen(input) + 1) { + /* note: for consistency to the handling of points, erroneous input is ignored. V4 addresses will use the mapped form + * (::ffff:192.0.2.1) */ + if (!inet_pton(AF_INET6, input, &addresses[index])) { + struct in_addr v4; + if (!inet_pton(AF_INET, input, &v4)) + continue; + ptls_build_v4_mapped_v6_address(&addresses[index], &v4); + } + if (memcmp(&addresses[index], &in6addr_any, sizeof(struct in6_addr)) == 0) + continue; + ++index; + } + addresses[index] = in6addr_any; + } + + /* find slot, or return if not available */ + size_t slot_index; + for (slot_index = 0; slot_index < PTLS_ELEMENTSOF(logctx.conns); ++slot_index) + if (logctx.conns[slot_index].points == NULL) + break; + if (slot_index == PTLS_ELEMENTSOF(logctx.conns)) { + ret = PTLS_ERROR_NO_MEMORY; + goto Exit; + } + + /* setup the slot */ + logctx.conns[slot_index].fd = fd; + logctx.conns[slot_index].points = points; + logctx.conns[slot_index].snis = snis; + logctx.conns[slot_index].addresses = addresses; + logctx.conns[slot_index].sample_ratio = sample_ratio; + logctx.conns[slot_index].appdata = appdata; + ++ptls_log._generation; + + ret = 0; /* success */ Exit: - ptls_buffer_dispose(buf); - return needs_appdata; + pthread_mutex_unlock(&logctx.mutex); + if (ret != 0) { + free(points); + free(snis); + free(addresses); + } + return ret; + +#else + return PTLS_ERROR_NOT_AVAILABLE; +#endif }