Skip to content

Commit 402544b

Browse files
kazuhokazuho
authored
Merge pull request #553 from h2o/kazuho/trace2
sampling-based tracing through Unix sockets
2 parents d13ff3b + a125f00 commit 402544b

File tree

3 files changed

+538
-91
lines changed

3 files changed

+538
-91
lines changed

‎include/picotls.h

Lines changed: 161 additions & 47 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,10 @@ extern "C" {
3434
#include <inttypes.h>
3535
#include <string.h>
3636
#include <sys/types.h>
37+
#ifndef _WINDOWS
38+
#include <netinet/in.h>
39+
#include <arpa/inet.h>
40+
#endif
3741

3842
#if __GNUC__ >= 3
3943
#define PTLS_LIKELY(x) __builtin_expect(!!(x), 1)
@@ -64,8 +68,15 @@ extern "C" {
6468
#define PTLS_THREADLOCAL __declspec(thread)
6569
#else
6670
#define PTLS_THREADLOCAL __thread
71+
#endif
72+
73+
#ifndef PTLS_HAVE_LOG
74+
#ifdef _WINDOWS
75+
#define PTLS_HAVE_LOG 0
76+
#else
6777
#define PTLS_HAVE_LOG 1
6878
#endif
79+
#endif
6980

7081
#ifndef PTLS_FUZZ_HANDSHAKE
7182
#define PTLS_FUZZ_HANDSHAKE 0
@@ -1386,35 +1397,44 @@ uint64_t ptls_decode_quicint(const uint8_t **src, const uint8_t *end);
13861397
ptls_decode_assert_block_close((src), end); \
13871398
} while (0)
13881399

1389-
#define PTLS_LOG__DO_LOG(module, type, block) \
1400+
#define PTLS_LOG__DO_LOG(module, name, conn_state, get_sni, get_sni_arg, add_time, block) \
13901401
do { \
1391-
int ptlslog_skip = 0; \
1392-
char smallbuf[128]; \
1393-
ptls_buffer_t ptlslogbuf; \
1394-
ptls_buffer_init(&ptlslogbuf, smallbuf, sizeof(smallbuf)); \
1395-
PTLS_LOG__DO_PUSH_SAFESTR("{\"module\":\"" PTLS_TO_STR(module) "\",\"type\":\"" PTLS_TO_STR(type) "\""); \
1402+
int ptlslog_skip = 0, ptlslog_include_appdata = 0; \
13961403
do { \
1397-
block \
1398-
} while (0); \
1399-
PTLS_LOG__DO_PUSH_SAFESTR("}\n"); \
1400-
if (!ptlslog_skip) \
1401-
ptls_log__do_write(&ptlslogbuf); \
1402-
ptls_buffer_dispose(&ptlslogbuf); \
1404+
char smallbuf[128]; \
1405+
ptls_buffer_t ptlslogbuf; \
1406+
ptls_log__do_write_start(&logpoint, &ptlslogbuf, smallbuf, sizeof(smallbuf), (add_time)); \
1407+
do { \
1408+
block \
1409+
} while (0); \
1410+
ptlslog_include_appdata = ptls_log__do_write_end(ptlslog_skip ? NULL : &logpoint, (conn_state), (get_sni), \
1411+
(get_sni_arg), &ptlslogbuf, ptlslog_include_appdata); \
1412+
} while (ptlslog_include_appdata); \
14031413
} while (0)
14041414

1405-
#define PTLS_LOG(module, type, block) \
1415+
#define PTLS_LOG_DEFINE_POINT(_module, _name, _var) \
1416+
static struct st_ptls_log_point_t _var = {.name = PTLS_TO_STR(_module) ":" PTLS_TO_STR(_name)}
1417+
1418+
#define PTLS_LOG(module, name, block) \
14061419
do { \
1407-
if (!ptls_log.is_active) \
1420+
PTLS_LOG_DEFINE_POINT(module, name, logpoint); \
1421+
if (ptls_log_point_maybe_active(&logpoint) == 0) \
14081422
break; \
1409-
PTLS_LOG__DO_LOG((module), (type), (block)); \
1423+
PTLS_LOG__DO_LOG(module, name, NULL, NULL, NULL, 1, {block}); \
14101424
} while (0)
14111425

1412-
#define PTLS_LOG_CONN(type, tls, block) \
1426+
#define PTLS_LOG_CONN(name, tls, block) \
14131427
do { \
1428+
PTLS_LOG_DEFINE_POINT(picotls, name, logpoint); \
1429+
uint32_t active = ptls_log_point_maybe_active(&logpoint); \
1430+
if (active == 0) \
1431+
break; \
14141432
ptls_t *_tls = (tls); \
1415-
if (!ptls_log.is_active || ptls_skip_tracing(_tls)) \
1433+
ptls_log_conn_state_t *conn_state = ptls_get_log_state(_tls); \
1434+
active &= ptls_log_conn_maybe_active(conn_state, (const char *(*)(void *))ptls_get_server_name, _tls); \
1435+
if (active == 0) \
14161436
break; \
1417-
PTLS_LOG__DO_LOG(picotls, type, { \
1437+
PTLS_LOG__DO_LOG(picotls, name, conn_state, (const char *(*)(void *))ptls_get_server_name, _tls, 1, { \
14181438
PTLS_LOG_ELEMENT_PTR(tls, _tls); \
14191439
do { \
14201440
block \
@@ -1461,14 +1481,14 @@ uint64_t ptls_decode_quicint(const uint8_t **src, const uint8_t *end);
14611481
#define PTLS_LOG_APPDATA_ELEMENT_UNSAFESTR(name, value, value_len) \
14621482
do { \
14631483
size_t _len = (value_len); \
1464-
if (ptls_log.include_appdata) \
1484+
if (ptlslog_include_appdata) \
14651485
PTLS_LOG_ELEMENT_UNSAFESTR(name, value, _len); \
14661486
PTLS_LOG_ELEMENT__DO_UNSIGNED(name, "_len", _len); \
14671487
} while (0)
14681488
#define PTLS_LOG_APPDATA_ELEMENT_HEXDUMP(name, value, value_len) \
14691489
do { \
14701490
size_t _len = (value_len); \
1471-
if (ptls_log.include_appdata) \
1491+
if (ptlslog_include_appdata) \
14721492
PTLS_LOG_ELEMENT_HEXDUMP(name, value, _len); \
14731493
PTLS_LOG_ELEMENT__DO_UNSIGNED(name, "_len", _len); \
14741494
} while (0)
@@ -1514,27 +1534,100 @@ uint64_t ptls_decode_quicint(const uint8_t **src, const uint8_t *end);
15141534
} while (0)
15151535

15161536
/**
1517-
* User API is exposed only when logging is supported by the platform.
1537+
* retains a list of connections that are bound to the object
1538+
*/
1539+
struct st_ptls_log_state_t {
1540+
/**
1541+
* bit array of connections (1 is active)
1542+
*/
1543+
uint32_t active_conns;
1544+
/**
1545+
* generation counter used for staleness check; see `ptls_log._generation`
1546+
*/
1547+
uint64_t generation;
1548+
};
1549+
1550+
/**
1551+
* represents a log point identified by name (`module:type`)
1552+
*/
1553+
struct st_ptls_log_point_t {
1554+
const char *name;
1555+
struct st_ptls_log_state_t state;
1556+
};
1557+
1558+
/**
1559+
* represents a logging state of each connection
1560+
*/
1561+
typedef struct st_ptls_log_conn_state_t {
1562+
/**
1563+
* random value between 0 (inclusive) and 1 (non-inclusive) used to determine the ratio of sampling-based logging; see
1564+
* `ptls_add_fd'`. To disable logging entirely, use `ptls_log.dummy_conn_state`, or set the value exactly to 1.
1565+
*/
1566+
float random_;
1567+
/**
1568+
* represents peer address; ipv4 addresses are stored using the mapped form (::ffff:192.0.2.1)
1569+
*/
1570+
struct in6_addr address;
1571+
struct st_ptls_log_state_t state;
1572+
} ptls_log_conn_state_t;
1573+
1574+
/**
1575+
* see `ptls_get_log_state`
1576+
*/
1577+
extern PTLS_THREADLOCAL ptls_log_conn_state_t *ptls_log_conn_state_override;
1578+
1579+
/**
1580+
* global variables exposed
1581+
*/
1582+
extern struct st_ptls_log_t {
1583+
/**
1584+
* if application-data (e.g., payload) should be emitted as well
1585+
*/
1586+
volatile unsigned may_include_appdata : 1;
1587+
/**
1588+
* endpoints that want to disable logging entirely can provide this value to the loggers
1589+
*/
1590+
ptls_log_conn_state_t dummy_conn_state;
1591+
/**
1592+
* generation counter that is incremented whenever the state of loggers change; see `st_ptls_log_state_t::generation`
1593+
*/
1594+
volatile uint64_t _generation;
1595+
} ptls_log;
1596+
1597+
/**
1598+
* initializes a ptls_log_conn_state_t
1599+
*/
1600+
void ptls_log_init_conn_state(ptls_log_conn_state_t *state, void (*random_bytes)(void *, size_t));
1601+
/**
1602+
* forces recalculation of the log state (should be called when SNI is determined)
15181603
*/
1519-
typedef struct st_ptls_log_t {
1520-
unsigned is_active : 1;
1521-
unsigned include_appdata : 1;
1522-
} ptls_log_t;
1604+
static void ptls_log_recalc_conn_state(ptls_log_conn_state_t *state);
1605+
/**
1606+
* returns a bitmap indicating the loggers active for given log point
1607+
*/
1608+
static uint32_t ptls_log_point_maybe_active(struct st_ptls_log_point_t *point);
1609+
/**
1610+
* returns a bitmap indicating the loggers active for given connection
1611+
*/
1612+
static uint32_t ptls_log_conn_maybe_active(ptls_log_conn_state_t *conn, const char *(*get_sni)(void *), void *get_sni_arg);
15231613

1524-
#if PTLS_HAVE_LOG
1525-
extern volatile ptls_log_t ptls_log;
15261614
/**
15271615
* Returns the number of log events that were unable to be emitted.
15281616
*/
15291617
size_t ptls_log_num_lost(void);
15301618
/**
1531-
* Registers an fd to the logger. A registered fd is automatically closed and removed if it is invalidated.
1619+
* Registers an fd to the logger. A registered fd is automatically closed and removed when it is closed by the peer.
1620+
* @param sample_ratio sampling ratio between 0 and 1
1621+
* @param points list of points to log, in the form of p1\0p2\0\0 (i.e., concatenated list of C strings with an empty string
1622+
* marking the end). An empty list means attach to all.
1623+
* @param snis list of SNIs to log, using the same form as points
1624+
* @param addresses list of IPv4/v6 addresses to log, using the same form as points
15321625
*/
1533-
int ptls_log_add_fd(int fd);
1534-
#else
1535-
static const ptls_log_t ptls_log = {0};
1536-
#endif
1626+
int ptls_log_add_fd(int fd, float sample_ratio, const char *points, const char *snis, const char *addresses, int appdata);
15371627

1628+
void ptls_log__recalc_point(int caller_locked, struct st_ptls_log_point_t *point);
1629+
void ptls_log__recalc_conn(int caller_locked, struct st_ptls_log_conn_state_t *conn, const char *(*get_sni)(void *),
1630+
void *get_sni_arg);
15381631
static int ptls_log__do_push_safestr(ptls_buffer_t *buf, const char *s);
15391632
int ptls_log__do_push_unsafestr(ptls_buffer_t *buf, const char *s, size_t l);
15401633
int ptls_log__do_push_hexdump(ptls_buffer_t *buf, const void *s, size_t l);
@@ -1543,7 +1636,10 @@ int ptls_log__do_push_signed32(ptls_buffer_t *buf, int32_t v);
15431636
int ptls_log__do_push_signed64(ptls_buffer_t *buf, int64_t v);
15441637
int ptls_log__do_push_unsigned32(ptls_buffer_t *buf, uint32_t v);
15451638
int ptls_log__do_push_unsigned64(ptls_buffer_t *buf, uint64_t v);
1546-
void ptls_log__do_write(const ptls_buffer_t *buf);
1639+
void ptls_log__do_write_start(struct st_ptls_log_point_t *point, ptls_buffer_t *buf, void *smallbuf, size_t smallbufsize,
1640+
int add_time);
1641+
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 *),
1642+
void *get_sni_arg, ptls_buffer_t *buf, int includes_appdata);
15471643

15481644
/**
15491645
* create a client object to handle new TLS connection
@@ -1648,13 +1744,11 @@ int ptls_is_ech_handshake(ptls_t *tls, uint8_t *config_id, ptls_hpke_kem_t **kem
16481744
*/
16491745
void **ptls_get_data_ptr(ptls_t *tls);
16501746
/**
1651-
*
1747+
* Returns `ptls_log_conn_state_t` of `ptls_t`. By default, the state is initialized by calling `ptls_log_init_conn_state`, but the
1748+
* behavior can be overidden by setting `ptls_log_conn_state_override`.
1749+
* This value can be changed by setting `ptls_log_random_override` or by calling `ptls_set_log_random`.
16521750
*/
1653-
int ptls_skip_tracing(ptls_t *tls);
1654-
/**
1655-
*
1656-
*/
1657-
void ptls_set_skip_tracing(ptls_t *tls, int skip_tracing);
1751+
ptls_log_conn_state_t *ptls_get_log_state(ptls_t *tls);
16581752
/**
16591753
* proceeds with the handshake, optionally taking some input from peer. The function returns zero in case the handshake completed
16601754
* successfully. PTLS_ERROR_IN_PROGRESS is returned in case the handshake is incomplete. Otherwise, an error value is returned. The
@@ -1890,6 +1984,11 @@ char *ptls_hexdump(char *dst, const void *src, size_t len);
18901984
* Builds a JSON-safe string without double quotes. Supplied buffer MUST be at least 6x + 1 bytes larger than the input.
18911985
*/
18921986
char *ptls_jsonescape(char *buf, const char *s, size_t len);
1987+
/**
1988+
* builds a v4-mapped address (i.e., ::ffff:192.0.2.1)
1989+
*/
1990+
void ptls_build_v4_mapped_v6_address(struct in6_addr *v6, const struct in_addr *v4);
1991+
18931992
/**
18941993
* the default get_time callback
18951994
*/
@@ -1898,17 +1997,32 @@ extern ptls_get_time_t ptls_get_time;
18981997
* default hash clone function that calls memcpy
18991998
*/
19001999
static void ptls_hash_clone_memcpy(void *dst, const void *src, size_t size);
1901-
#if defined(PICOTLS_USE_DTRACE) && PICOTLS_USE_DTRACE
1902-
/**
1903-
*
1904-
*/
1905-
extern PTLS_THREADLOCAL unsigned ptls_default_skip_tracing;
1906-
#else
1907-
#define ptls_default_skip_tracing 0
1908-
#endif
19092000

19102001
/* inline functions */
19112002

2003+
inline uint32_t ptls_log_point_maybe_active(struct st_ptls_log_point_t *point)
2004+
{
2005+
if (!PTLS_HAVE_LOG)
2006+
return 0;
2007+
if (PTLS_UNLIKELY(point->state.generation != ptls_log._generation))
2008+
ptls_log__recalc_point(0, point);
2009+
return point->state.active_conns;
2010+
}
2011+
2012+
inline void ptls_log_recalc_conn_state(ptls_log_conn_state_t *state)
2013+
{
2014+
state->state.generation = 0;
2015+
}
2016+
2017+
inline uint32_t ptls_log_conn_maybe_active(ptls_log_conn_state_t *conn, const char *(*get_sni)(void *), void *get_sni_arg)
2018+
{
2019+
if (!PTLS_HAVE_LOG)
2020+
return 0;
2021+
if (PTLS_UNLIKELY(conn->state.generation != ptls_log._generation))
2022+
ptls_log__recalc_conn(0, conn, get_sni, get_sni_arg);
2023+
return conn->state.active_conns;
2024+
}
2025+
19122026
inline int ptls_log__do_push_safestr(ptls_buffer_t *buf, const char *s)
19132027
{
19142028
return ptls_log__do_pushv(buf, s, strlen(s));

0 commit comments

Comments
 (0)