Skip to content

Commit

Permalink
H2: Use H2S_Lock_VSLb() when logging to the sess vsl
Browse files Browse the repository at this point in the history
  • Loading branch information
@walid-git
walid-git committed Aug 6, 2024
1 parent 98d9fa4 commit 55be1d8
Show file tree
Hide file tree
Showing 4 changed files with 23 additions and 45 deletions.
6 changes: 3 additions & 3 deletions bin/varnishd/http2/cache_http2_hpack.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -325,7 +325,7 @@ h2h_decode_hdr_fini(const struct h2_sess *h2)
"HPACK compression error/fini (%s)", VHD_Error(d->vhd_ret));
ret = H2CE_COMPRESSION_ERROR;
} else if (d->error == NULL && !d->has_scheme) {
VSLb(h2->vsl, SLT_Debug, "Missing :scheme");
H2S_Lock_VSLb(h2, SLT_Debug, "Missing :scheme");
ret = H2SE_MISSING_SCHEME; //rfc7540,l,3087,3090
} else
ret = d->error;
Expand Down Expand Up @@ -377,7 +377,7 @@ h2h_decode_bytes(struct h2_sess *h2, const uint8_t *in, size_t in_l)
d->out, d->out_l, &d->out_u);

if (d->vhd_ret < 0) {
VSLb(hp->vsl, SLT_BogoHeader,
H2S_Lock_VSLb(h2, SLT_BogoHeader,
"HPACK compression error (%s)",
VHD_Error(d->vhd_ret));
d->error = H2CE_COMPRESSION_ERROR;
Expand Down Expand Up @@ -449,7 +449,7 @@ h2h_decode_bytes(struct h2_sess *h2, const uint8_t *in, size_t in_l)
if (d->limit < 0) {
/* Fatal error, the client exceeded both http_req_size
* and h2_max_header_list_size. */
VSLb(h2->vsl, SLT_SessError, "Header list too large");
H2S_Lock_VSLb(h2, SLT_SessError, "Header list too large");
return (H2CE_ENHANCE_YOUR_CALM);
}

Expand Down
52 changes: 16 additions & 36 deletions bin/varnishd/http2/cache_http2_proto.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -357,9 +357,7 @@ h2_rapid_reset(struct worker *wrk, struct h2_sess *h2, struct h2_req *r2)
h2->last_rst = now;

if (h2->rst_budget < 1.0) {
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Error, "H2: Hit RST limit. Closing session.");
Lck_Unlock(&h2->sess->mtx);
H2S_Lock_VSLb(h2, SLT_Error, "H2: Hit RST limit. Closing session.");
return (H2CE_RAPID_RESET);
}
h2->rst_budget -= 1.0;
Expand Down Expand Up @@ -399,9 +397,7 @@ h2_rx_goaway(struct worker *wrk, struct h2_sess *h2, struct h2_req *r2)
h2->goaway = 1;
h2->goaway_last_stream = vbe32dec(h2->rxf_data);
h2->error = h2_connectionerror(vbe32dec(h2->rxf_data + 4));
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug, "GOAWAY %s", h2->error->name);
Lck_Unlock(&h2->sess->mtx);
H2S_Lock_VSLb(h2, SLT_Debug, "GOAWAY %s", h2->error->name);
return (h2->error);
}

Expand Down Expand Up @@ -534,19 +530,15 @@ h2_set_setting(struct h2_sess *h2, const uint8_t *d)
y = vbe32dec(d + 2);
if (x >= H2_SETTING_TBL_LEN || h2_setting_tbl[x] == NULL) {
// rfc7540,l,2181,2182
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug,
H2S_Lock_VSLb(h2, SLT_Debug,
"H2SETTING unknown setting 0x%04x=%08x (ignored)", x, y);
Lck_Unlock(&h2->sess->mtx);
return (0);
}
s = h2_setting_tbl[x];
AN(s);
if (y < s->minval || y > s->maxval) {
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug, "H2SETTING invalid %s=0x%08x",
H2S_Lock_VSLb(h2, SLT_Debug, "H2SETTING invalid %s=0x%08x",
s->name, y);
Lck_Unlock(&h2->sess->mtx);
AN(s->range_error);
if (!DO_DEBUG(DBG_H2_NOCHECK))
return (s->range_error);
Expand Down Expand Up @@ -638,9 +630,7 @@ h2_end_headers(struct worker *wrk, struct h2_sess *h2,
h2e = h2h_decode_hdr_fini(h2);
h2->new_req = NULL;
if (h2e != NULL) {
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug, "HPACK/FINI %s", h2e->name);
Lck_Unlock(&h2->sess->mtx);
H2S_Lock_VSLb(h2, SLT_Debug, "HPACK/FINI %s", h2e->name);
assert(!WS_IsReserved(r2->req->ws));
h2_del_req(wrk, r2);
return (h2e);
Expand All @@ -655,7 +645,7 @@ h2_end_headers(struct worker *wrk, struct h2_sess *h2,
cl = http_GetContentLength(req->http);
assert(cl >= -2);
if (cl == -2) {
VSLb(h2->vsl, SLT_Debug, "Non-parseable Content-Length");
H2S_Lock_VSLb(h2, SLT_Debug, "Non-parseable Content-Length");
return (H2SE_PROTOCOL_ERROR);
}

Expand All @@ -682,12 +672,12 @@ h2_end_headers(struct worker *wrk, struct h2_sess *h2,
}

if (req->http->hd[HTTP_HDR_METHOD].b == NULL) {
VSLb(h2->vsl, SLT_Debug, "Missing :method");
H2S_Lock_VSLb(h2, SLT_Debug, "Missing :method");
return (H2SE_PROTOCOL_ERROR); //rfc7540,l,3087,3090
}

if (req->http->hd[HTTP_HDR_URL].b == NULL) {
VSLb(h2->vsl, SLT_Debug, "Missing :path");
H2S_Lock_VSLb(h2, SLT_Debug, "Missing :path");
return (H2SE_PROTOCOL_ERROR); //rfc7540,l,3087,3090
}

Expand All @@ -696,7 +686,7 @@ h2_end_headers(struct worker *wrk, struct h2_sess *h2,
if (*req->http->hd[HTTP_HDR_URL].b == '*' &&
(Tlen(req->http->hd[HTTP_HDR_METHOD]) != 7 ||
strncmp(req->http->hd[HTTP_HDR_METHOD].b, "OPTIONS", 7))) {
VSLb(h2->vsl, SLT_BogoHeader, "Illegal :path pseudo-header");
H2S_Lock_VSLb(h2, SLT_BogoHeader, "Illegal :path pseudo-header");
return (H2SE_PROTOCOL_ERROR); //rfc7540,l,3068,3071
}

Expand Down Expand Up @@ -734,7 +724,7 @@ h2_rx_headers(struct worker *wrk, struct h2_sess *h2, struct h2_req *r2)
*/
if (h2->open_streams >=
(int)h2->local_settings.max_concurrent_streams) {
VSLb(h2->vsl, SLT_Debug,
H2S_Lock_VSLb(h2, SLT_Debug,
"H2: stream %u: Hit maximum number of "
"concurrent streams", h2->rxf_stream);
return (H2SE_REFUSED_STREAM); // rfc7540,l,1200,1205
Expand Down Expand Up @@ -786,9 +776,7 @@ h2_rx_headers(struct worker *wrk, struct h2_sess *h2, struct h2_req *r2)
}
h2e = h2h_decode_bytes(h2, p, l);
if (h2e != NULL) {
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug, "HPACK(hdr) %s", h2e->name);
Lck_Unlock(&h2->sess->mtx);
H2S_Lock_VSLb(h2, SLT_Debug, "HPACK(hdr) %s", h2e->name);
(void)h2h_decode_hdr_fini(h2);
assert(!WS_IsReserved(r2->req->ws));
h2_del_req(wrk, r2);
Expand Down Expand Up @@ -821,9 +809,7 @@ h2_rx_continuation(struct worker *wrk, struct h2_sess *h2, struct h2_req *r2)
h2e = h2h_decode_bytes(h2, h2->rxf_data, h2->rxf_len);
r2->req->acct.req_hdrbytes += h2->rxf_len;
if (h2e != NULL) {
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug, "HPACK(cont) %s", h2e->name);
Lck_Unlock(&h2->sess->mtx);
H2S_Lock_VSLb(h2, SLT_Debug, "HPACK(cont) %s", h2e->name);
(void)h2h_decode_hdr_fini(h2);
assert(!WS_IsReserved(r2->req->ws));
h2_del_req(wrk, r2);
Expand Down Expand Up @@ -1008,11 +994,11 @@ h2_rx_data(struct worker *wrk, struct h2_sess *h2, struct h2_req *r2)
stvbuf = STV_AllocBuf(wrk, stv_h2_rxbuf,
bufsize + sizeof *rxbuf);
if (stvbuf == NULL) {
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug,
"H2: stream %u: Failed to allocate request body"
" buffer",
h2->rxf_stream);
Lck_Lock(&h2->sess->mtx);
r2->error = H2SE_INTERNAL_ERROR;
if (r2->cond)
PTOK(pthread_cond_signal(r2->cond));
Expand Down Expand Up @@ -1285,10 +1271,8 @@ h2_procframe(struct worker *wrk, struct h2_sess *h2, h2_frame h2f)
// rfc7540,l,1140,1145
// rfc7540,l,1153,1158
/* No even streams, we don't do PUSH_PROMISE */
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug, "H2: illegal stream (=%u)",
H2S_Lock_VSLb(h2, SLT_Debug, "H2: illegal stream (=%u)",
h2->rxf_stream);
Lck_Unlock(&h2->sess->mtx);
return (H2CE_PROTOCOL_ERROR);
}

Expand Down Expand Up @@ -1492,11 +1476,9 @@ h2_rxframe(struct worker *wrk, struct h2_sess *h2)
// rfc7540,l,679,681
// XXX: later, drain rest of frame
h2->bogosity++;
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug,
H2S_Lock_VSLb(h2, SLT_Debug,
"H2: Unknown frame type 0x%02x (ignored)",
(uint8_t)h2->rxf_type);
Lck_Unlock(&h2->sess->mtx);
h2->srq->acct.req_bodybytes += h2->rxf_len;
return (1);
}
Expand All @@ -1510,11 +1492,9 @@ h2_rxframe(struct worker *wrk, struct h2_sess *h2)
if (h2->rxf_flags & ~h2f->flags) {
// rfc7540,l,687,688
h2->bogosity++;
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug,
H2S_Lock_VSLb(h2, SLT_Debug,
"H2: Unknown flags 0x%02x on %s (ignored)",
(uint8_t)h2->rxf_flags & ~h2f->flags, h2f->name);
Lck_Unlock(&h2->sess->mtx);
h2->rxf_flags &= h2f->flags;
}

Expand Down
6 changes: 2 additions & 4 deletions bin/varnishd/http2/cache_http2_send.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -209,7 +209,7 @@ H2_Send_Frame(struct worker *wrk, struct h2_sess *h2,
s = writev(h2->sess->fd, iov, len == 0 ? 1 : 2);
if (s != sizeof hdr + len) {
if (errno == EWOULDBLOCK) {
VSLb(h2->vsl, SLT_Debug,
H2S_Lock_VSLb(h2, SLT_Debug,
"H2: stream %u: Hit idle_send_timeout", stream);
}
/*
Expand Down Expand Up @@ -414,9 +414,7 @@ H2_Send_RST(struct worker *wrk, struct h2_sess *h2, const struct h2_req *r2,
AN(H2_SEND_HELD(h2, r2));
AN(h2e);

Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug, "H2: stream %u: %s", stream, h2e->txt);
Lck_Unlock(&h2->sess->mtx);
H2S_Lock_VSLb(h2, SLT_Debug, "H2: stream %u: %s", stream, h2e->txt);
vbe32enc(b, h2e->val);

H2_Send_Frame(wrk, h2, H2_F_RST_STREAM, 0, sizeof b, stream, b);
Expand Down
4 changes: 2 additions & 2 deletions bin/varnishd/http2/cache_http2_session.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -429,7 +429,7 @@ h2_new_session(struct worker *wrk, void *arg)
while (h2_rxframe(wrk, h2)) {
HTC_RxInit(h2->htc, h2->ws);
if (WS_Overflowed(h2->ws)) {
VSLb(h2->vsl, SLT_Debug, "H2: Empty Rx Workspace");
H2S_Lock_VSLb(h2, SLT_SessError, "H2: Empty Rx Workspace");
h2->error = H2CE_INTERNAL_ERROR;
break;
}
Expand All @@ -439,8 +439,8 @@ h2_new_session(struct worker *wrk, void *arg)
AN(h2->error);

/* Delete all idle streams */
VSLb(h2->vsl, SLT_Debug, "H2 CLEANUP %s", h2->error->name);
Lck_Lock(&h2->sess->mtx);
VSLb(h2->vsl, SLT_Debug, "H2 CLEANUP %s", h2->error->name);
VTAILQ_FOREACH(r2, &h2->streams, list) {
if (r2->error == 0)
r2->error = h2->error;
Expand Down

0 comments on commit 55be1d8

Please sign in to comment.