[master] b909dd5c3 http2: Do not log SessError for HTC_S_TIMEOUT and HTC_S_EOF

[Nils Goroll]

commit b909dd5c363c2c75f081f4740fc246d3ecf5a4ec
Author: Nils Goroll <nils.goroll at uplex.de>
Date:   Mon Mar 3 17:15:45 2025 +0100

    http2: Do not log SessError for HTC_S_TIMEOUT and HTC_S_EOF
    
    We no longer send "real" H2CE error codes when the connection is simply EOF or
    timed out, but we did still emit SessError.
    
    We now limit it to unhandled HTC status and add to the additional Debug output
    the HTC status.

diff --git a/bin/varnishd/http2/cache_http2_proto.c b/bin/varnishd/http2/cache_http2_proto.c
index b624050a6..254275ebd 100644
--- a/bin/varnishd/http2/cache_http2_proto.c
+++ b/bin/varnishd/http2/cache_http2_proto.c
@@ -1460,11 +1460,16 @@ h2_sweep(struct worker *wrk, struct h2_sess *h2)
  * goaway currently is always 0, see #4285
  */
 static void
-h2_eof_debug(struct h2_sess *h2)
+h2_htc_debug(enum htc_status_e hs, struct h2_sess *h2)
 {
+	const char *s, *r;
+
+	if (LIKELY(VSL_tag_is_masked(SLT_Debug)))
+		return;
 
-	H2S_Lock_VSLb(h2, SLT_Debug, "H2: eof frame=%s goaway=%d",
-	    h2->htc->rxbuf_b == h2->htc->rxbuf_e ? "complete" : "partial",
+	HTC_Status(hs, &s, &r);
+	H2S_Lock_VSLb(h2, SLT_Debug, "H2: HTC %s (%s) frame=%s goaway=%d",
+	    s, r, h2->htc->rxbuf_b == h2->htc->rxbuf_e ? "complete" : "partial",
 	    h2->goaway);
 }
 
@@ -1504,8 +1509,7 @@ h2_rxframe(struct worker *wrk, struct h2_sess *h2)
 	h2e = NULL;
 	switch (hs) {
 	case HTC_S_EOF:
-		h2_eof_debug(h2);
-
+		h2_htc_debug(hs, h2);
 		h2e = H2CE_NO_ERROR;
 		break;
 	case HTC_S_COMPLETE:
@@ -1514,15 +1518,17 @@ h2_rxframe(struct worker *wrk, struct h2_sess *h2)
 			h2e = h2_sweep(wrk, h2);
 		break;
 	case HTC_S_TIMEOUT:
+		//// #4279
+		// h2_htc_debug(hs, h2);
 		h2e = h2_sweep(wrk, h2);
 		break;
 	default:
+		HTC_Status(hs, &s, &r);
+		H2S_Lock_VSLb(h2, SLT_SessError, "H2: HTC %s (%s)", s, r);
 		h2e = H2CE_ENHANCE_YOUR_CALM;
 	}
 
 	if (h2e != NULL && h2e->connection) {
-		HTC_Status(hs, &s, &r);
-		H2S_Lock_VSLb(h2, SLT_SessError, "H2: HTC %s (%s)", s, r);
 		h2->error = h2e;
 		h2_tx_goaway(wrk, h2, h2e);
 		return (0);
diff --git a/bin/varnishtest/tests/t02027.vtc b/bin/varnishtest/tests/t02027.vtc
index b88dd9953..02bad0f7c 100644
--- a/bin/varnishtest/tests/t02027.vtc
+++ b/bin/varnishtest/tests/t02027.vtc
@@ -8,13 +8,14 @@ varnish v1 -arg "-p feature=+http2" -arg "-p debug=+syncvsl" -vcl {
 } -start
 
 logexpect l0 -v v1 -g vxid -q "Begin ~ sess" {
+	fail add * SessError
 	expect * * Debug           {^H2: Got pu PRISM}
-	expect 0 = Debug           {^H2: eof frame=complete goaway=0}
-	expect 0 = SessError       {^H2: HTC eof}
+	expect 0 = Debug           {^H2: HTC eof.*frame=complete goaway=0}
 	expect 0 = Debug           {^H2 CLEANUP H2CE_NO_ERROR}
 	expect 0 = ReqAcct         {^0 0 0 18 26 44}
 	expect 0 = SessClose       {^REM_CLOSE}
 	expect 0 = End
+	fail clear
 } -start
 
 # no streams open
@@ -24,12 +25,13 @@ client c0 {
 } -run
 
 logexpect l1 -v v1 -g vxid -q "Begin ~ sess" {
-	expect * * Debug           {^H2: eof frame=complete goaway=0}
-	expect 0 = SessError       {^H2: HTC eof}
+	fail add * SessError
+	expect * * Debug           {^H2: HTC eof.*frame=complete goaway=0}
 	expect 0 = Debug           {^H2 CLEANUP H2CE_NO_ERROR}
 	expect 9 = ReqAcct         {^27 0 27 27 26 53}
 	expect 0 = SessClose       {^REM_CLOSE}
 	expect 0 = End
+	fail clear
 } -start
 
 # after frame, no END_HEADERS
@@ -41,12 +43,13 @@ client c1 {
 } -run
 
 logexpect l2 -v v1 -g vxid -q "Begin ~ sess" {
-	expect * * Debug           {^H2: eof frame=complete goaway=0}
-	expect 0 = SessError       {^H2: HTC eof}
+	fail add * SessError
+	expect * * Debug           {^H2: HTC eof.*frame=complete goaway=0}
 	expect 0 = Debug           {^H2 CLEANUP H2CE_NO_ERROR}
 	expect 9 = ReqAcct         {^27 0 27 27 26 53}
 	expect 0 = SessClose       {^REM_CLOSE}
 	expect 0 = End
+	fail clear
 } -start
 
 # after frame, no END_STREAM
@@ -58,12 +61,13 @@ client c2 {
 } -run
 
 logexpect l3 -v v1 -g vxid -q "Begin ~ sess" {
-	expect * * Debug           {^H2: eof frame=partial goaway=0}
-	expect 0 = SessError       {^H2: HTC eof}
+	fail add * SessError
+	expect * * Debug           {^H2: HTC eof.*frame=partial goaway=0}
 	expect 0 = Debug           {^H2 CLEANUP H2CE_NO_ERROR}
 	expect 0 = ReqAcct         {^18 0 18 27 26 53}
 	expect 0 = SessClose       {^REM_CLOSE}
 	expect 0 = End
+	fail clear
 } -start
 
 # middle of frame