[master] 6093812b2 vca: Log the outcome of sockopt inheritance

[Nils Goroll]

commit 6093812b22b2f09e99b4e1560d0aa6e275a4795b
Author: Dridi Boukelmoune <dridi.boukelmoune at gmail.com>
Date:   Mon Nov 15 12:31:02 2021 +0100

    vca: Log the outcome of sockopt inheritance

diff --git a/bin/varnishd/cache/cache_acceptor.c b/bin/varnishd/cache/cache_acceptor.c
index d00725c0b..2eaadb228 100644
--- a/bin/varnishd/cache/cache_acceptor.c
+++ b/bin/varnishd/cache/cache_acceptor.c
@@ -240,15 +240,27 @@ vca_sock_opt_test(const struct listen_sock *ls, const struct sess *sp)
 	for (n = 0; n < n_sock_opts; n++) {
 		so = &sock_opts[n];
 		ch = &ls->conn_heritage[n];
-		if (ch->sess_set)
-			continue; /* Already set, no need to retest */
-		if (so->level == IPPROTO_TCP && ls->uds)
+		if (ch->sess_set) {
+			VSL(SLT_Debug, sp->vxid,
+			    "sockopt: Not testing nonhereditary %s for %s=%s",
+			    so->strname, ls->name, ls->endpoint);
 			continue;
+		}
+		if (so->level == IPPROTO_TCP && ls->uds) {
+			VSL(SLT_Debug, sp->vxid,
+			    "sockopt: Not testing incompatible %s for %s=%s",
+			    so->strname, ls->name, ls->endpoint);
+			continue;
+		}
 		memset(&tmp, 0, sizeof tmp);
 		l = so->sz;
 		i = getsockopt(sp->fd, so->level, so->optname, &tmp, &l);
-		if (i == 0 && memcmp(&tmp, so->arg, so->sz))
+		if (i == 0 && memcmp(&tmp, so->arg, so->sz)) {
+			VSL(SLT_Debug, sp->vxid,
+			    "sockopt: Test confirmed %s non heredity for %s=%s",
+			    so->strname, ls->name, ls->endpoint);
 			ch->sess_set = 1;
+		}
 		if (i && errno != ENOPROTOOPT)
 			VTCP_Assert(i);
 	}
@@ -259,21 +271,44 @@ vca_sock_opt_set(const struct listen_sock *ls, const struct sess *sp)
 {
 	struct conn_heritage *ch;
 	struct sock_opt *so;
+	unsigned vxid;
 	int n, sock;
 
 	CHECK_OBJ_NOTNULL(ls, LISTEN_SOCK_MAGIC);
-	CHECK_OBJ_ORNULL(sp, SESS_MAGIC);
-	sock = sp != NULL ? sp->fd : ls->sock;
+
+	if (sp != NULL) {
+		CHECK_OBJ(sp, SESS_MAGIC);
+		sock = sp->fd;
+		vxid = sp->vxid;
+	} else {
+		sock = ls->sock;
+		vxid = 0;
+	}
 
 	for (n = 0; n < n_sock_opts; n++) {
 		so = &sock_opts[n];
 		ch = &ls->conn_heritage[n];
-		if (so->level == IPPROTO_TCP && ls->uds)
+		if (so->level == IPPROTO_TCP && ls->uds) {
+			VSL(SLT_Debug, vxid,
+			    "sockopt: Not setting incompatible %s for %s=%s",
+			    so->strname, ls->name, ls->endpoint);
 			continue;
-		if (sp == NULL && ch->listen_mod == so->mod)
+		}
+		if (sp == NULL && ch->listen_mod == so->mod) {
+			VSL(SLT_Debug, vxid,
+			    "sockopt: Not setting unmodified %s for %s=%s",
+			    so->strname, ls->name, ls->endpoint);
 			continue;
-		if  (sp != NULL && !ch->sess_set)
+		}
+		if  (sp != NULL && !ch->sess_set) {
+			VSL(SLT_Debug, sp->vxid,
+			    "sockopt: %s may be inherited for %s=%s",
+			    so->strname, ls->name, ls->endpoint);
 			continue;
+		}
+		VSL(SLT_Debug, vxid,
+		    "sockopt: Setting %s for %s=%s",
+		    so->strname, ls->name, ls->endpoint);
 		VTCP_Assert(setsockopt(sock,
 		    so->level, so->optname, so->arg, so->sz));
 		if (sp == NULL)
diff --git a/bin/varnishtest/tests/l00000.vtc b/bin/varnishtest/tests/l00000.vtc
index 1c732fc47..e7e316ccf 100644
--- a/bin/varnishtest/tests/l00000.vtc
+++ b/bin/varnishtest/tests/l00000.vtc
@@ -11,7 +11,7 @@ varnish v1 -vcl+backend {
 logexpect l1 -v v1 -g session {
 	expect 0 1000	Begin		sess
 	expect 0 =	SessOpen
-	expect 0 =	Link		"req 1001"
+	expect * =	Link		"req 1001"
 	expect 0 =	SessClose
 	expect 0 =	End
 
diff --git a/bin/varnishtest/tests/o00001.vtc b/bin/varnishtest/tests/o00001.vtc
index 5a6b35913..ebe38bcb9 100644
--- a/bin/varnishtest/tests/o00001.vtc
+++ b/bin/varnishtest/tests/o00001.vtc
@@ -74,7 +74,7 @@ logexpect l1 -v v1 -g raw {
 	expect * 1016	Proxy		"2 1.2.3.4 2314 5.6.7.8 2828"
 	expect * 1019	Proxy		"2 102:304:506::d0e:f10 2314 8182:8384:8586::8d8e:8f80 2828"
 	expect * 1022	Begin		"^sess 0 PROXY"
-	expect 1 1022	SessClose	"^RX_OVERFLOW"
+	expect * 1022	SessClose	"^RX_OVERFLOW"
 } -start
 
 client c1 {
diff --git a/bin/varnishtest/tests/o00006.vtc b/bin/varnishtest/tests/o00006.vtc
index 5f7eb4638..e8adecb7c 100644
--- a/bin/varnishtest/tests/o00006.vtc
+++ b/bin/varnishtest/tests/o00006.vtc
@@ -12,7 +12,7 @@ varnish v1 -arg "-p pool_sess=0,0,0" -proto "PROXY" -vcl+backend {} -start
 logexpect l1 -v v1 -g raw {
 	expect 0 1000	Begin		"sess 0 PROXY"
 	expect 0 =	SessOpen
-	expect 0 =	Proxy		"2 217.70.181.33 60822 95.142.168.34 443"
+	expect * =	Proxy		"2 217.70.181.33 60822 95.142.168.34 443"
 	expect 0 =	Error		{\Qinsufficient workspace (proto_priv)\E}
 	expect 0 =	SessClose	"RX_JUNK"
 } -start
diff --git a/bin/varnishtest/tests/r01804.vtc b/bin/varnishtest/tests/r01804.vtc
index 252dd5845..d50bf9558 100644
--- a/bin/varnishtest/tests/r01804.vtc
+++ b/bin/varnishtest/tests/r01804.vtc
@@ -13,7 +13,7 @@ varnish v1 -vcl+backend "" -start
 logexpect l1 -v v1 -g session {
 	expect * 1000	Begin		{^sess .* PROXY$}
 	expect 0 =	SessOpen	{^.* foo .*}
-	expect 0 =	Proxy		{^1 }
+	expect * =	Proxy		{^1 }
 	expect * 1001	Begin		{^req}
 } -start
 
@@ -28,7 +28,7 @@ logexpect l1 -wait
 logexpect l2 -v v1 -g session {
 	expect * 1003	Begin		{^sess .* PROXY$}
 	expect 0 =	SessOpen	{^.* foo .*}
-	expect 0 =	Proxy		{^2 }
+	expect * =	Proxy		{^2 }
 	expect * 1004	Begin		{^req}
 } -start
 
diff --git a/bin/varnishtest/tests/r02722.vtc b/bin/varnishtest/tests/r02722.vtc
index e8a4eef61..1268864b5 100644
--- a/bin/varnishtest/tests/r02722.vtc
+++ b/bin/varnishtest/tests/r02722.vtc
@@ -9,7 +9,7 @@ server s0 {
         txresp
 } -dispatch
 
-varnish v1 -arg {-a :0 -a "${tmpdir}/v1.sock"}
+varnish v1 -arg {-a TCP=:0 -a "UDS=${tmpdir}/v1.sock"}
 varnish v1 -cliok "param.set debug +flush_head"
 varnish v1 -cliok "param.set timeout_idle 1"
 varnish v1 -vcl+backend { } -start