[master] 07a785ebf vsl: Apply VSL_OPT_E to the Begin[4] field
Dridi Boukelmoune
dridi.boukelmoune at gmail.com
Tue Aug 16 06:31:08 UTC 2022
commit 07a785ebfae9b942c4ce88fd9ba74d1cfbca655c
Author: Dridi Boukelmoune <dridi.boukelmoune at gmail.com>
Date: Fri Jul 22 15:17:54 2022 +0200
vsl: Apply VSL_OPT_E to the Begin[4] field
As I was relying on the lack of -E option to discard another type of
non-ESI sub-requests I recently misled myself with this assumption. It
took me a while to realize that I was also seeing transactions I was not
interested in, corrupting the statistics I was deriving from a log dump.
Now that vmod_pesi [1] sets the precedent, we should expect new types of
sub-requests to materialize and expecting the reason for the transaction
to be "esi" is no longer appropriate.
We could also track this field as vtx::sub_level for example, to make it
available as VSL query LHS operand. The focus here was to adjust the
behavior of an existing feature, not add a new one.
[1] https://code.uplex.de/uplex-varnish/libvdp-pesi
diff --git a/bin/varnishtest/tests/l00007.vtc b/bin/varnishtest/tests/l00007.vtc
new file mode 100644
index 000000000..0416dd9e6
--- /dev/null
+++ b/bin/varnishtest/tests/l00007.vtc
@@ -0,0 +1,125 @@
+varnishtest "Begin[4] and VSL_OPT_E"
+
+varnish v1 -vcl {
+ import vtc;
+
+ backend be none;
+
+ sub vcl_init {
+ # make up a replay with -i Begin,Link,End
+ vtc.vsl_replay({"
+**** v1 vsl| 1000 Begin c sess 0 HTTP/1
+**** v1 vsl| 1000 Link c req 1001 rxreq
+**** v1 vsl| 1003 Begin b bereq 1002 fetch
+**** v1 vsl| 1003 End b
+**** v1 vsl| 1002 Begin c req 1001 vmod_foo:subreq 1
+**** v1 vsl| 1002 End c
+**** v1 vsl| 1001 Begin c req 1000 rxreq
+**** v1 vsl| 1001 Link c req 1002 vmod_foo:subreq 1
+**** v1 vsl| 1001 End c
+**** v1 vsl| 1000 End c
+**** v1 vsl| 1004 Begin c sess 0 HTTP/1
+**** v1 vsl| 1004 End c
+ "});
+ }
+} -start
+
+varnish v1 -vsl_catchup
+
+logexpect l1 -v v1 -d 1 {
+ expect 0 1003 Begin "bereq 1002 fetch"
+ expect 0 = End
+ expect 0 1001 Begin "req 1000 rxreq"
+ expect 0 = Link "req 1002 vmod_foo:subreq"
+ expect 0 = End
+ expect 0 1000 Begin "sess 0 HTTP/1"
+ expect 0 = Link "req 1001 rxreq"
+ expect 0 = End
+ expect 0 1004 Begin "sess 0 HTTP/1"
+ expect 0 = End
+} -run
+
+logexpect l1_bis -v v1 -d 1 -b 1 -c 1 {
+ expect 0 1003 Begin "bereq 1002 fetch"
+ expect 0 = End
+ expect 0 1001 Begin "req 1000 rxreq"
+ expect 0 = Link "req 1002 vmod_foo:subreq"
+ expect 0 = End
+ expect 0 1000 Begin "sess 0 HTTP/1"
+ expect 0 = Link "req 1001 rxreq"
+ expect 0 = End
+ expect 0 1004 Begin "sess 0 HTTP/1"
+ expect 0 = End
+} -run
+
+logexpect l2 -v v1 -d 1 -b 1 {
+ expect 0 1003 Begin "bereq 1002 fetch"
+ expect 0 = End
+} -run
+
+logexpect l3 -v v1 -d 1 -c 1 {
+ expect 0 1001 Begin "req 1000 rxreq"
+ expect 0 = Link "req 1002 vmod_foo:subreq"
+ expect 0 = End
+ expect 0 1000 Begin "sess 0 HTTP/1"
+ expect 0 = Link "req 1001 rxreq"
+ expect 0 = End
+ expect 0 1004 Begin "sess 0 HTTP/1"
+ expect 0 = End
+} -run
+
+logexpect l4 -v v1 -d 1 -E 1 {
+ expect 0 1002 Begin "req 1001 vmod_foo:subreq"
+ expect 0 = End
+ expect 0 1001 Begin "req 1000 rxreq"
+ expect 0 = Link "req 1002 vmod_foo:subreq"
+ expect 0 = End
+ expect 0 1000 Begin "sess 0 HTTP/1"
+ expect 0 = Link "req 1001 rxreq"
+ expect 0 = End
+ expect 0 1004 Begin "sess 0 HTTP/1"
+ expect 0 = End
+} -run
+
+logexpect l4_bis -v v1 -d 1 -c 1 -E 1 {
+ expect 0 1002 Begin "req 1001 vmod_foo:subreq"
+ expect 0 = End
+ expect 0 1001 Begin "req 1000 rxreq"
+ expect 0 = Link "req 1002 vmod_foo:subreq"
+ expect 0 = End
+ expect 0 1000 Begin "sess 0 HTTP/1"
+ expect 0 = Link "req 1001 rxreq"
+ expect 0 = End
+ expect 0 1004 Begin "sess 0 HTTP/1"
+ expect 0 = End
+} -run
+
+logexpect l5 -v v1 -d 1 -b 1 -E 1 {
+ expect 0 1003 Begin "bereq 1002 fetch"
+ expect 0 = End
+ expect 0 1002 Begin "req 1001 vmod_foo:subreq"
+ expect 0 = End
+ expect 0 1001 Begin "req 1000 rxreq"
+ expect 0 = Link "req 1002 vmod_foo:subreq"
+ expect 0 = End
+ expect 0 1000 Begin "sess 0 HTTP/1"
+ expect 0 = Link "req 1001 rxreq"
+ expect 0 = End
+ expect 0 1004 Begin "sess 0 HTTP/1"
+ expect 0 = End
+} -run
+
+logexpect l5_bis -v v1 -d 1 -b 1 -c 1 -E 1 {
+ expect 0 1003 Begin "bereq 1002 fetch"
+ expect 0 = End
+ expect 0 1002 Begin "req 1001 vmod_foo:subreq"
+ expect 0 = End
+ expect 0 1001 Begin "req 1000 rxreq"
+ expect 0 = Link "req 1002 vmod_foo:subreq"
+ expect 0 = End
+ expect 0 1000 Begin "sess 0 HTTP/1"
+ expect 0 = Link "req 1001 rxreq"
+ expect 0 = End
+ expect 0 1004 Begin "sess 0 HTTP/1"
+ expect 0 = End
+} -run
diff --git a/include/vapi/vapi_options.h b/include/vapi/vapi_options.h
index 498ed08ed..3cff3eb47 100644
--- a/include/vapi/vapi_options.h
+++ b/include/vapi/vapi_options.h
@@ -54,7 +54,9 @@
#define VSL_OPT_E \
VOPT("E", "[-E]", "Display ESI transactions", \
- "Display ESI transactions and other client transactions." \
+ "Display ESI transactions and other types of sub-requests." \
+ " This implies the -c option and includes other client" \
+ " transactions." \
)
#define VSL_OPT_i \
diff --git a/lib/libvarnishapi/vsl.c b/lib/libvarnishapi/vsl.c
index e5f2ddaf1..0a7b2cbf1 100644
--- a/lib/libvarnishapi/vsl.c
+++ b/lib/libvarnishapi/vsl.c
@@ -190,10 +190,12 @@ VSL_Match(struct VSL_data *vsl, const struct VSL_cursor *c)
tag = VSL_TAG(c->rec.ptr);
if (tag <= SLT__Bogus || tag >= SLT__Reserved)
return (0);
- if (vsl->c_opt && !VSL_CLIENT(c->rec.ptr))
- return (0);
- if (vsl->b_opt && !VSL_BACKEND(c->rec.ptr))
- return (0);
+ if (!vsl->c_opt || !vsl->b_opt) {
+ if (vsl->c_opt && !VSL_CLIENT(c->rec.ptr))
+ return (0);
+ if (vsl->b_opt && !VSL_BACKEND(c->rec.ptr))
+ return (0);
+ }
if (!VTAILQ_EMPTY(&vsl->vslf_select) &&
vsl_match_IX(vsl, &vsl->vslf_select, c))
return (1);
diff --git a/lib/libvarnishapi/vsl_dispatch.c b/lib/libvarnishapi/vsl_dispatch.c
index db3c30ee1..8c24a7521 100644
--- a/lib/libvarnishapi/vsl_dispatch.c
+++ b/lib/libvarnishapi/vsl_dispatch.c
@@ -689,10 +689,10 @@ vtx_set_parent(struct vtx *parent, struct vtx *child)
successfully parsed. */
static int
vtx_parse_link(const char *str, enum VSL_transaction_e *ptype,
- unsigned *pvxid, enum VSL_reason_e *preason)
+ unsigned *pvxid, enum VSL_reason_e *preason, unsigned *psub)
{
char type[16], reason[16];
- unsigned vxid;
+ unsigned vxid, sub;
int i;
enum VSL_transaction_e et;
enum VSL_reason_e er;
@@ -702,7 +702,7 @@ vtx_parse_link(const char *str, enum VSL_transaction_e *ptype,
AN(pvxid);
AN(preason);
- i = sscanf(str, "%15s %u %15s", type, &vxid, reason);
+ i = sscanf(str, "%15s %u %15s %u", type, &vxid, reason, &sub);
if (i < 1)
return (0);
@@ -729,7 +729,13 @@ vtx_parse_link(const char *str, enum VSL_transaction_e *ptype,
if (er >= VSL_r__MAX)
er = VSL_r_unknown;
*preason = er;
- return (3);
+ if (i == 3)
+ return (3);
+
+ /* request sub-level */
+ if (psub != NULL)
+ *psub = sub;
+ return (4);
}
/* Parse and process a begin record */
@@ -746,8 +752,8 @@ vtx_scan_begin(struct VSLQ *vslq, struct vtx *vtx, const uint32_t *ptr)
AZ(vtx->flags & VTX_F_READY);
- i = vtx_parse_link(VSL_CDATA(ptr), &type, &p_vxid, &reason);
- if (i != 3)
+ i = vtx_parse_link(VSL_CDATA(ptr), &type, &p_vxid, &reason, NULL);
+ if (i < 3)
return (vtx_diag_tag(vtx, ptr, "parse error"));
if (type == VSL_t_unknown)
(void)vtx_diag_tag(vtx, ptr, "unknown vxid type");
@@ -813,8 +819,8 @@ vtx_scan_link(struct VSLQ *vslq, struct vtx *vtx, const uint32_t *ptr)
AZ(vtx->flags & VTX_F_READY);
- i = vtx_parse_link(VSL_CDATA(ptr), &c_type, &c_vxid, &c_reason);
- if (i != 3)
+ i = vtx_parse_link(VSL_CDATA(ptr), &c_type, &c_vxid, &c_reason, NULL);
+ if (i < 3)
return (vtx_diag_tag(vtx, ptr, "parse error"));
if (c_type == VSL_t_unknown)
(void)vtx_diag_tag(vtx, ptr, "unknown vxid type");
@@ -1288,7 +1294,7 @@ vslq_candidate(struct VSLQ *vslq, const uint32_t *ptr)
enum VSL_reason_e reason;
struct VSL_data *vsl;
enum VSL_tag_e tag;
- unsigned p_vxid;
+ unsigned p_vxid, sub;
int i;
CHECK_OBJ_NOTNULL(vslq, VSLQ_MAGIC);
@@ -1302,24 +1308,24 @@ vslq_candidate(struct VSLQ *vslq, const uint32_t *ptr)
CHECK_OBJ_NOTNULL(vsl, VSL_MAGIC);
if (vslq->grouping == VSL_g_vxid) {
if (!vsl->c_opt && !vsl->b_opt)
- return (1); /* Implies also !vsl->E_opt */
- if (!vsl->b_opt && !VSL_CLIENT(ptr))
+ AZ(vsl->E_opt);
+ else if (!vsl->b_opt && !VSL_CLIENT(ptr))
return (0);
- if (!vsl->c_opt && !VSL_BACKEND(ptr))
+ else if (!vsl->c_opt && !VSL_BACKEND(ptr))
return (0);
/* Need to parse the Begin tag - fallthrough to below */
}
tag = VSL_TAG(ptr);
assert(tag == SLT_Begin);
- i = vtx_parse_link(VSL_CDATA(ptr), &type, &p_vxid, &reason);
- if (i != 3 || type == VSL_t_unknown)
+ i = vtx_parse_link(VSL_CDATA(ptr), &type, &p_vxid, &reason, &sub);
+ if (i < 3 || type == VSL_t_unknown)
return (0);
- if (type == VSL_t_sess)
+ if (vslq->grouping == VSL_g_request && type == VSL_t_sess)
return (0);
- if (vslq->grouping == VSL_g_vxid && reason == VSL_r_esi && !vsl->E_opt)
+ if (vslq->grouping == VSL_g_vxid && i > 3 && sub > 0 && !vsl->E_opt)
return (0);
return (1);
More information about the varnish-commit
mailing list