Skip to content

V
varnish-cache
Commit 86b3f9fe authored by Martin Blix Grydeland's avatar Martin Blix Grydeland
Browse files
Options

Log proxy related messages on the session, not on the request. 

The proxy log records were attempted to be logged on the request' log
buffer, which at that point in time has not yet been set up and does
not posess a VXID. This caused VXID==0 log records to be inserted in
the beginning of the log for the first request on the session when
using proxy protocol, and subsequently the VSL to fail picking them
out as valid request log transactions.

Fix by logging the PROXY handling related messages on the session, in
which they belong.

Fixes: #1804
parent e70fe44a
Hide whitespace changes
Inline Side-by-side
Showing with 57 additions and 16 deletions
bin/varnishd/proxy/cache_proxy_proto.c
View file @ 86b3f9fe
......@@ -62,8 +62,9 @@ vpx_proto1(const struct worker *wrk, struct req *req)
CHECK_OBJ_NOTNULL(wrk, WORKER_MAGIC);
CHECK_OBJ_NOTNULL(req, REQ_MAGIC);
CHECK_OBJ_NOTNULL(req->sp, SESS_MAGIC);
VSL(SLT_Debug, req->sp->fd, "PROXY1");
VSL(SLT_Debug, req->sp->vxid, "PROXY1");
q = strchr(req->htc->rxbuf_b, '\r');
if (q == NULL)
......@@ -80,7 +81,7 @@ vpx_proto1(const struct worker *wrk, struct req *req)
for (i = 0; i < 5; i++) {
p = strchr(p, ' ');
if (p == NULL) {
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY1: Too few fields");
return (-1);
}
......@@ -89,7 +90,7 @@ vpx_proto1(const struct worker *wrk, struct req *req)
}
if (strchr(p, ' ')) {
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY1: Too many fields");
return (-1);
}
......@@ -102,7 +103,7 @@ vpx_proto1(const struct worker *wrk, struct req *req)
else if (!strcmp(fld[0], "TCP6"))
pfam = AF_INET6;
else {
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY1: Wrong TCP[46] field");
return (-1);
}
......@@ -113,14 +114,14 @@ vpx_proto1(const struct worker *wrk, struct req *req)
i = getaddrinfo(fld[1], fld[3], &hints, &res);
if (i != 0) {
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY1: Cannot resolve source address (%s)",
gai_strerror(i));
return (-1);
}
AZ(res->ai_next);
if (res->ai_family != pfam) {
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY1: %s got wrong protocol (%d)",
fld[0], res->ai_family);
freeaddrinfo(res);
......@@ -134,14 +135,14 @@ vpx_proto1(const struct worker *wrk, struct req *req)
i = getaddrinfo(fld[2], fld[4], &hints, &res);
if (i != 0) {
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY1: Cannot resolve destination address (%s)",
gai_strerror(i));
return (-1);
}
AZ(res->ai_next);
if (res->ai_family != pfam) {
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY1: %s got wrong protocol (%d)",
fld[0], res->ai_family);
freeaddrinfo(res);
......@@ -151,7 +152,7 @@ vpx_proto1(const struct worker *wrk, struct req *req)
AN(VSA_Build(sa, res->ai_addr, res->ai_addrlen));
freeaddrinfo(res);
VSLb(req->vsl, SLT_Proxy, "1 %s %s %s %s",
VSL(SLT_Proxy, req->sp->vxid, "1 %s %s %s %s",
fld[1], fld[3], fld[2], fld[4]);
req->htc->pipeline_b = q;
return (0);
......@@ -182,6 +183,7 @@ vpx_proto2(const struct worker *wrk, struct req *req)
CHECK_OBJ_NOTNULL(wrk, WORKER_MAGIC);
CHECK_OBJ_NOTNULL(req, REQ_MAGIC);
CHECK_OBJ_NOTNULL(req->sp, SESS_MAGIC);
assert(req->htc->rxbuf_e - req->htc->rxbuf_b >= 16L);
l = vbe16dec(req->htc->rxbuf_b + 14);
......@@ -191,7 +193,7 @@ vpx_proto2(const struct worker *wrk, struct req *req)
/* Version @12 top half */
if ((p[12] >> 4) != 2) {
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY2: bad version (%d)", p[12] >> 4);
return (-1);
}
......@@ -205,7 +207,7 @@ vpx_proto2(const struct worker *wrk, struct req *req)
/* Proxied connection */
break;
default:
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY2: bad command (%d)", p[12] & 0x0f);
return (-1);
}
......@@ -214,14 +216,14 @@ vpx_proto2(const struct worker *wrk, struct req *req)
switch(p[13]) {
case 0x00:
/* UNSPEC|UNSPEC, ignore proxy header */
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY2: Ignoring UNSPEC|UNSPEC addresses");
return (0);
case 0x11:
/* IPv4|TCP */
pfam = AF_INET;
if (l < 12) {
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY2: Ignoring short IPv4 addresses (%d)", l);
return (0);
}
......@@ -230,14 +232,14 @@ vpx_proto2(const struct worker *wrk, struct req *req)
/* IPv6|TCP */
pfam = AF_INET6;
if (l < 36) {
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY2: Ignoring short IPv6 addresses (%d)", l);
return (0);
}
break;
default:
/* Ignore proxy header */
VSLb(req->vsl, SLT_ProxyGarbage,
VSL(SLT_ProxyGarbage, req->sp->vxid,
"PROXY2: Ignoring unsupported protocol (0x%02x)", p[13]);
return (0);
}
......@@ -286,7 +288,7 @@ vpx_proto2(const struct worker *wrk, struct req *req)
SES_Set_String_Attr(req->sp, SA_CLIENT_IP, hb);
SES_Set_String_Attr(req->sp, SA_CLIENT_PORT, pb);
VSLb(req->vsl, SLT_Proxy, "2 %s %s %s %s", hb, pb, ha, pa);
VSL(SLT_Proxy, req->sp->vxid, "2 %s %s %s %s", hb, pb, ha, pa);
return (0);
}
......
bin/varnishtest/tests/r01804.vtc 0 → 100644
View file @ 86b3f9fe
varnishtest "#1804: varnishapi transaction grouping fails for PROXY"
server s1 {
rxreq
txresp
} -start
varnish v1 -proto "PROXY" -vcl+backend {
} -start
logexpect l1 -v v1 -d 0 -g session {
expect * * Begin {^sess .* PROXY$}
expect * = Proxy {^1 }
expect * * Begin {^req}
expect * * Begin {^sess .* PROXY$}
expect * = Proxy {^2 }
expect * * Begin {^req}
} -start
client c1 {
send "PROXY TCP4 1.2.3.4 5.6.7.8 1234 5678\r\n"
txreq
rxresp
} -run
client c2 {
# good IPv4
sendhex "0d 0a 0d 0a 00 0d 0a 51 55 49 54 0a"
sendhex "21 11 00 0c"
sendhex "01 02 03 04"
sendhex "05 06 07 08"
sendhex "09 0a"
sendhex "0b 0c"
txreq
rxresp
} -run
logexpect l1 -wait
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment