diff --git a/src/mux_h2.c b/src/mux_h2.c index 16ed74305b..5684940882 100644 --- a/src/mux_h2.c +++ b/src/mux_h2.c @@ -840,6 +840,80 @@ static int h2_avail_streams(struct connection *conn) return ret1; } +/* inconditionally produce a trace of the header. Please do not call this one + * and use h2_trace_header() instead which first checks if traces are enabled. + */ +void _h2_trace_header(const struct ist hn, const struct ist hv, + uint64_t mask, const struct ist trc_loc, const char *func, + const struct h2c *h2c, const struct h2s *h2s) +{ + struct ist n_ist, v_ist; + const char *c_str, *s_str; + + chunk_reset(&trash); + c_str = chunk_newstr(&trash); + if (h2c) { + chunk_appendf(&trash, "h2c=%p(%c,%s) ", + h2c, (h2c->flags & H2_CF_IS_BACK) ? 'B' : 'F', h2c_st_to_str(h2c->st0)); + } + + s_str = chunk_newstr(&trash); + if (h2s) { + if (h2s->id <= 0) + chunk_appendf(&trash, "dsi=%d ", h2s->h2c->dsi); + chunk_appendf(&trash, "h2s=%p(%d,%s) ", h2s, h2s->id, h2s_st_to_str(h2s->st)); + } + else if (h2c) + chunk_appendf(&trash, "dsi=%d ", h2c->dsi); + + n_ist = ist2(chunk_newstr(&trash), 0); + istscpy(&n_ist, hn, 256); + trash.data += n_ist.len; + if (n_ist.len != hn.len) + chunk_appendf(&trash, " (... +%ld)", (long)(hn.len - n_ist.len)); + + v_ist = ist2(chunk_newstr(&trash), 0); + istscpy(&v_ist, hv, 1024); + trash.data += v_ist.len; + if (v_ist.len != hv.len) + chunk_appendf(&trash, " (... +%ld)", (long)(hv.len - v_ist.len)); + + TRACE_PRINTF_LOC(TRACE_LEVEL_USER, mask, trc_loc, func, + h2c->conn, 0, 0, 0, + "%s%s%s %s: %s", c_str, s_str, + (mask & H2_EV_TX_HDR) ? "sndh" : "rcvh", + n_ist.ptr, v_ist.ptr); +} + +/* produce a trace of the header after checking that tracing is enabled */ +static inline void h2_trace_header(const struct ist hn, const struct ist hv, + uint64_t mask, const struct ist trc_loc, const char *func, + const struct h2c *h2c, const struct h2s *h2s) +{ + if ((TRACE_SOURCE)->verbosity >= H2_VERB_ADVANCED && + TRACE_ENABLED(TRACE_LEVEL_USER, mask, h2c ? h2c->conn : 0, h2s, 0, 0)) + _h2_trace_header(hn, hv, mask, trc_loc, func, h2c, h2s); +} + +/* hpack-encode header name and value , possibly emitting a trace if + * currently enabled. This is done on behalf of function at + * passed as ist(TRC_LOC), h2c , and h2s , all of which may be NULL. + * The trace is only emitted if the header is emitted (in which case non-zero + * is returned). The trash is modified. In the traces, the header's name will + * be truncated to 256 chars and the header's value to 1024 chars. + */ +static inline int h2_encode_header(struct buffer *buf, const struct ist hn, const struct ist hv, + uint64_t mask, const struct ist trc_loc, const char *func, + const struct h2c *h2c, const struct h2s *h2s) +{ + int ret; + + ret = hpack_encode_header(buf, hn, hv); + if (ret) + h2_trace_header(hn, hv, mask, trc_loc, func, h2c, h2s); + + return ret; +} /*****************************************************************/ /* functions below are dedicated to the mux setup and management */ @@ -4729,6 +4803,26 @@ static int h2c_decode_headers(struct h2c *h2c, struct buffer *rxbuf, uint32_t *f /* past this point we cannot roll back in case of error */ outlen = hpack_decode_frame(h2c->ddht, hdrs, flen, list, sizeof(list)/sizeof(list[0]), tmp); + + if (outlen > 0 && + (TRACE_SOURCE)->verbosity >= H2_VERB_ADVANCED && + TRACE_ENABLED(TRACE_LEVEL_USER, H2_EV_RX_FRAME|H2_EV_RX_HDR, h2c->conn, 0, 0, 0)) { + struct ist n; + int i; + + for (i = 0; list[i].n.len; i++) { + n = list[i].n; + + if (!isttest(n)) { + /* this is in fact a pseudo header whose number is in n.len */ + n = h2_phdr_to_ist(n.len); + } + + h2_trace_header(n, list[i].v, H2_EV_RX_FRAME|H2_EV_RX_HDR, + ist(TRC_LOC), __FUNCTION__, h2c, NULL); + } + } + if (outlen < 0) { TRACE_STATE("failed to decompress HPACK", H2_EV_RX_FRAME|H2_EV_RX_HDR|H2_EV_H2C_ERR|H2_EV_PROTO_ERR, h2c->conn); h2c_error(h2c, H2_ERR_COMPRESSION_ERROR); @@ -5113,6 +5207,14 @@ static size_t h2s_frt_make_resp_headers(struct h2s *h2s, struct htx *htx) goto full; } + if ((TRACE_SOURCE)->verbosity >= H2_VERB_ADVANCED) { + char sts[4]; + + h2_trace_header(ist(":status"), ist(ultoa_r(h2s->status, sts, sizeof(sts))), + H2_EV_TX_FRAME|H2_EV_TX_HDR, ist(TRC_LOC), __FUNCTION__, + h2c, h2s); + } + /* encode all headers, stop at empty name */ for (hdr = 0; hdr < sizeof(list)/sizeof(list[0]); hdr++) { /* these ones do not exist in H2 and must be dropped. */ @@ -5130,7 +5232,8 @@ static size_t h2s_frt_make_resp_headers(struct h2s *h2s, struct htx *htx) if (isteq(list[hdr].n, ist(""))) break; // end - if (!hpack_encode_header(&outbuf, list[hdr].n, list[hdr].v)) { + if (!h2_encode_header(&outbuf, list[hdr].n, list[hdr].v, H2_EV_TX_FRAME|H2_EV_TX_HDR, + ist(TRC_LOC), __FUNCTION__, h2c, h2s)) { /* output full */ if (b_space_wraps(mbuf)) goto realign_again; @@ -5390,6 +5493,8 @@ static size_t h2s_bck_make_req_headers(struct h2s *h2s, struct htx *htx) goto full; } + h2_trace_header(ist(":method"), meth, H2_EV_TX_FRAME|H2_EV_TX_HDR, ist(TRC_LOC), __FUNCTION__, h2c, h2s); + auth = ist(NULL); /* RFC7540 #8.3: the CONNECT method must have : @@ -5403,12 +5508,14 @@ static size_t h2s_bck_make_req_headers(struct h2s *h2s, struct htx *htx) if (unlikely(sl->info.req.meth == HTTP_METH_CONNECT) && !extended_connect) { auth = uri; - if (!hpack_encode_header(&outbuf, ist(":authority"), auth)) { + if (!h2_encode_header(&outbuf, ist(":authority"), auth, H2_EV_TX_FRAME|H2_EV_TX_HDR, + ist(TRC_LOC), __FUNCTION__, h2c, h2s)) { /* output full */ if (b_space_wraps(mbuf)) goto realign_again; goto full; } + h2s->flags |= H2_SF_BODY_TUNNEL; } else { /* other methods need a :scheme. If an authority is known from @@ -5468,7 +5575,9 @@ static size_t h2s_bck_make_req_headers(struct h2s *h2s, struct htx *htx) goto full; } - if (auth.len && !hpack_encode_header(&outbuf, ist(":authority"), auth)) { + if (auth.len && + !h2_encode_header(&outbuf, ist(":authority"), auth, H2_EV_TX_FRAME|H2_EV_TX_HDR, + ist(TRC_LOC), __FUNCTION__, h2c, h2s)) { /* output full */ if (b_space_wraps(mbuf)) goto realign_again; @@ -5492,15 +5601,16 @@ static size_t h2s_bck_make_req_headers(struct h2s *h2s, struct htx *htx) goto full; } + h2_trace_header(ist(":path"), uri, H2_EV_TX_FRAME|H2_EV_TX_HDR, ist(TRC_LOC), __FUNCTION__, h2c, h2s); + /* encode the pseudo-header protocol from rfc8441 if using * Extended CONNECT method. */ if (unlikely(extended_connect)) { const struct ist protocol = ist(h2s->upgrade_protocol); if (isttest(protocol)) { - if (!hpack_encode_header(&outbuf, - ist(":protocol"), - protocol)) { + if (!h2_encode_header(&outbuf, ist(":protocol"), protocol, H2_EV_TX_FRAME|H2_EV_TX_HDR, + ist(TRC_LOC), __FUNCTION__, h2c, h2s)) { /* output full */ if (b_space_wraps(mbuf)) goto realign_again; @@ -5543,7 +5653,7 @@ static size_t h2s_bck_make_req_headers(struct h2s *h2s, struct htx *htx) if (isteq(n, ist(""))) break; // end - if (!hpack_encode_header(&outbuf, n, v)) { + if (!h2_encode_header(&outbuf, n, v, H2_EV_TX_FRAME|H2_EV_TX_HDR, ist(TRC_LOC), __FUNCTION__, h2c, h2s)) { /* output full */ if (b_space_wraps(mbuf)) goto realign_again; @@ -6091,7 +6201,8 @@ static size_t h2s_make_trailers(struct h2s *h2s, struct htx *htx) if (*(list[idx].n.ptr) == ':') continue; - if (!hpack_encode_header(&outbuf, list[idx].n, list[idx].v)) { + if (!h2_encode_header(&outbuf, list[idx].n, list[idx].v, H2_EV_TX_FRAME|H2_EV_TX_HDR, + ist(TRC_LOC), __FUNCTION__, h2c, h2s)) { /* output full */ if (b_space_wraps(mbuf)) goto realign_again;