Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Varnisncsa: Change matching rules to reflect reality #4213

Open
wants to merge 5 commits into
base: master
Choose a base branch
from
Open

Varnisncsa: Change matching rules to reflect reality #4213

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
e1fff87
varnishncsa: Replace "force" flag with an update mode enum
walid-git Oct 11, 2024
9c2cfb9
varnishncsa: Add an update mode argument to process_hdr
walid-git Oct 11, 2024
7f5fed1
varnishncsa: Keep track of when vcl_{recv,backend_response} were seen
walid-git Oct 11, 2024
7468e9a
varnishncsa: Change matching rules to reflect reality
walid-git Oct 11, 2024
b6c21ef
varnishncsa: Take [BE]{Req,Resp}Unset into account
walid-git Oct 11, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
99 changes: 74 additions & 25 deletions bin/varnishncsa/varnishncsa.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -160,8 +160,26 @@ static struct ctx {
const char *handling;
const char *side;
int64_t vxid;
int vcl_recv_seen;
int vcl_br_seen;
Comment on lines +163 to +164
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think I would prefer more neutral names like recd_req and recd_beresp. What tells us today that we are done receiving a request or backend response are VCL_Call logs but it could change in the future.

For example, we set X-Forwarded-For before entering vcl_recv so we could consider a new log record between the last ReqHeader coming from the client and the first ReqHeader coming from varnishd.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Wouldn't it be better to add some new vsl tag that indicates the end of reception from a peer so that we can rely on it in varnishncsa and avoid taking headers added by the core code before vcl_recv/vcl_backend_response into account ?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should focus on the new model for NCSA formats here.

} CTX;

enum update_mode {
UM_NEVER,
UM_IF_NOT_SET,
UM_ALWAYS
};

#define UPDATE_REQ_C(CTX) (CTX.vcl_recv_seen ? UM_NEVER : UM_ALWAYS)
#define UPDATE_REQ_B(CTX) (CTX.vcl_br_seen ? UM_NEVER : UM_ALWAYS)

#define UPDATE_REQ(CTX) (*CTX.side == 'b' ? UPDATE_REQ_B(CTX) : UPDATE_REQ_C(CTX))

#define UPDATE_RESP_C(CTX) (UM_ALWAYS)
#define UPDATE_RESP_B(CTX) (CTX.vcl_br_seen ? UM_NEVER : UM_ALWAYS)

#define UPDATE_RESP(CTX) (*CTX.side == 'b' ? UPDATE_RESP_B(CTX) : UPDATE_RESP_C(CTX))
Comment on lines +167 to +181
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think I would prefer something like this:

enum format_policy {
        FMTPOL_FIRST,
        FMTPOL_REQ,
        FMTPOL_RESP,
        FMTPOL_BEREQ,
        FMTPOL_BERESP,
};

Remember that you always have access to CTX to apply the policy, so we shouldn't need macros. A single function could tell you what to do:

static unsigned
process_format(enum format_policy fp)
{

        /* switch (fp) => check CTX */
}

Then you can use that in functions like frag_fields() to bail out early:

if (!process_format(fp))
        return;

It might prevent cascading enum arguments, I could only have a quick look at the patch series.


static void parse_format(const char *format);

static void
Expand Down Expand Up @@ -850,7 +868,7 @@ isprefix(const char *prefix, size_t len, const char *b,
}

static void
frag_fields(int force, const char *b, const char *e, ...)
frag_fields(enum update_mode um, const char *b, const char *e, ...)
{
va_list ap;
const char *p, *q;
Expand Down Expand Up @@ -882,7 +900,8 @@ frag_fields(int force, const char *b, const char *e, ...)
assert(p != NULL && q != NULL);
if (p >= e || q <= p)
continue;
if (frag->gen != CTX.gen || force) {
if ((frag->gen != CTX.gen && um == UM_IF_NOT_SET)
|| um == UM_ALWAYS) {
/* We only grab the same matching field once */
frag->gen = CTX.gen;
frag->b = p;
Expand All @@ -893,10 +912,12 @@ frag_fields(int force, const char *b, const char *e, ...)
}

static void
frag_line(int force, const char *b, const char *e, struct fragment *f)
frag_line(enum update_mode um, const char *b, const char *e, struct fragment *f)
{
if (um == UM_NEVER)
return;

if (f->gen == CTX.gen && !force)
if (f->gen == CTX.gen && um == UM_IF_NOT_SET)
/* We only grab the same matching record once */
return;

Expand All @@ -914,7 +935,8 @@ frag_line(int force, const char *b, const char *e, struct fragment *f)
}

static void
process_hdr(const struct watch_head *head, const char *b, const char *e)
process_hdr(const struct watch_head *head, const char *b, const char *e,
enum update_mode um, int unset)
{
struct watch *w;
const char *p;
Expand All @@ -923,7 +945,12 @@ process_hdr(const struct watch_head *head, const char *b, const char *e)
CHECK_OBJ_NOTNULL(w, WATCH_MAGIC);
if (!isprefix(w->key, w->keylen, b, e, &p))
continue;
frag_line(1, p, e, &w->frag);
if (unset) {
frag_line(um, CTX.missing_string,
CTX.missing_string + strlen(CTX.missing_string),
&w->frag);
} else
frag_line(um, p, e, &w->frag);
}
}

Expand All @@ -942,9 +969,9 @@ process_vsl(const struct vsl_watch_head *head, enum VSL_tag_e tag,
!isprefix(w->prefix, w->prefixlen, b, e, &p))
continue;
if (w->idx == 0)
frag_line(0, p, e, &w->frag);
frag_line(UM_IF_NOT_SET, p, e, &w->frag);
else
frag_fields(0, p, e, w->idx, &w->frag, 0, NULL);
frag_fields(UM_IF_NOT_SET, p, e, w->idx, &w->frag, 0, NULL);
}
}

Expand All @@ -971,6 +998,8 @@ dispatch_f(struct VSL_data *vsl, struct VSL_transaction * const pt[],
} else
continue;

CTX.vcl_recv_seen = 0;
CTX.vcl_br_seen = 0;
CTX.hitmiss = "-";
CTX.handling = "-";
CTX.vxid = t->vxid;
Expand All @@ -993,44 +1022,49 @@ dispatch_f(struct VSL_data *vsl, struct VSL_transaction * const pt[],
skip = 1;
break;
case SLT_PipeAcct:
frag_fields(0, b, e,
frag_fields(UM_IF_NOT_SET, b, e,
3, &CTX.frag[F_I],
4, &CTX.frag[F_O],
0, NULL);
break;
case SLT_BackendOpen:
frag_fields(1, b, e,
frag_fields(UM_ALWAYS, b, e,
3, &CTX.frag[F_h],
0, NULL);
break;
case SLT_ReqStart:
frag_fields(0, b, e,
frag_fields(UM_IF_NOT_SET, b, e,
1, &CTX.frag[F_h],
0, NULL);
break;
case SLT_BereqMethod:
case SLT_ReqMethod:
frag_line(0, b, e, &CTX.frag[F_m]);
frag_line(UPDATE_REQ(CTX),
b, e, &CTX.frag[F_m]);
break;
case SLT_BereqURL:
case SLT_ReqURL:
p = memchr(b, '?', e - b);
if (p == NULL)
p = e;
frag_line(0, b, p, &CTX.frag[F_U]);
frag_line(0, p, e, &CTX.frag[F_q]);
frag_line(UPDATE_REQ(CTX),
b, p, &CTX.frag[F_U]);
frag_line(UPDATE_REQ(CTX),
p, e, &CTX.frag[F_q]);
break;
case SLT_BereqProtocol:
case SLT_ReqProtocol:
frag_line(0, b, e, &CTX.frag[F_H]);
frag_line(UPDATE_REQ(CTX),
b, e, &CTX.frag[F_H]);
break;
case SLT_BerespStatus:
case SLT_RespStatus:
frag_line(1, b, e, &CTX.frag[F_s]);
frag_line(UPDATE_RESP(CTX),
b, e, &CTX.frag[F_s]);
break;
case SLT_BereqAcct:
case SLT_ReqAcct:
frag_fields(0, b, e,
frag_fields(UM_IF_NOT_SET, b, e,
3, &CTX.frag[F_I],
5, &CTX.frag[F_b],
6, &CTX.frag[F_O],
Expand All @@ -1039,40 +1073,53 @@ dispatch_f(struct VSL_data *vsl, struct VSL_transaction * const pt[],
case SLT_Timestamp:
#define ISPREFIX(a, b, c, d) isprefix(a, strlen(a), b, c, d)
if (ISPREFIX("Start:", b, e, &p)) {
frag_fields(0, p, e, 1,
frag_fields(UM_IF_NOT_SET, p, e, 1,
&CTX.frag[F_tstart], 0, NULL);

} else if (ISPREFIX("Resp:", b, e, &p) ||
ISPREFIX("PipeSess:", b, e, &p) ||
ISPREFIX("BerespBody:", b, e, &p)) {
frag_fields(0, p, e, 1,
frag_fields(UM_IF_NOT_SET, p, e, 1,
&CTX.frag[F_tend], 0, NULL);

} else if (ISPREFIX("Process:", b, e, &p) ||
ISPREFIX("Pipe:", b, e, &p) ||
ISPREFIX("Beresp:", b, e, &p)) {
frag_fields(0, p, e, 2,
frag_fields(UM_IF_NOT_SET, p, e, 2,
&CTX.frag[F_ttfb], 0, NULL);
}
break;
case SLT_BereqHeader:
case SLT_ReqHeader:
process_hdr(&CTX.watch_reqhdr, b, e);
process_hdr(&CTX.watch_reqhdr, b, e,
UPDATE_REQ(CTX), 0);
if (ISPREFIX("Authorization:", b, e, &p) &&
ISPREFIX("basic ", p, e, &p))
frag_line(0, p, e,
frag_line(UPDATE_REQ(CTX), p, e,
&CTX.frag[F_auth]);
else if (ISPREFIX("Host:", b, e, &p))
frag_line(0, p, e,
frag_line(UPDATE_REQ(CTX), p, e,
&CTX.frag[F_host]);
#undef ISPREFIX
break;
case SLT_BerespHeader:
case SLT_RespHeader:
process_hdr(&CTX.watch_resphdr, b, e);
process_hdr(&CTX.watch_resphdr, b, e,
UPDATE_RESP(CTX), 0);
break;
case SLT_BereqUnset:
case SLT_ReqUnset:
process_hdr(&CTX.watch_reqhdr, b, e,
UPDATE_REQ(CTX), 1);
break;
case SLT_BerespUnset:
case SLT_RespUnset:
process_hdr(&CTX.watch_resphdr, b, e,
UPDATE_RESP(CTX), 1);
break;
case SLT_VCL_call:
if (!strcasecmp(b, "recv")) {
CTX.vcl_recv_seen = 1;
CTX.hitmiss = "-";
CTX.handling = "-";
} else if (!strcasecmp(b, "hit")) {
Expand All @@ -1090,6 +1137,8 @@ dispatch_f(struct VSL_data *vsl, struct VSL_transaction * const pt[],
wrong */
CTX.hitmiss = "miss";
CTX.handling = "synth";
} else if (!strcasecmp(b, "backend_response")) {
CTX.vcl_br_seen = 1;
}
break;
case SLT_VCL_return:
Expand All @@ -1106,7 +1155,7 @@ dispatch_f(struct VSL_data *vsl, struct VSL_transaction * const pt[],
strncmp(b, w->key, w->keylen))
continue;
p = b + w->keylen;
frag_line(0, p, e, &w->frag);
frag_line(UM_IF_NOT_SET, p, e, &w->frag);
}
break;
default:
Expand Down
Loading