[4.0] 6f2e1bc Request handling byte accounting
Martin Blix Grydeland
martin at varnish-software.com
Tue Apr 1 15:09:55 CEST 2014
commit 6f2e1bcd343a7a745ac01aa61e8ce0e66b3bb6cc
Author: Martin Blix Grydeland <martin at varnish-software.com>
Date: Fri Mar 28 11:25:38 2014 +0100
Request handling byte accounting
Counters show bytes received/transmitted, split between header and
body bytes.
SLT_ReqAcct logs per request counter values.
diff --git a/bin/varnishd/cache/cache.h b/bin/varnishd/cache/cache.h
index b793467..de7d895 100644
--- a/bin/varnishd/cache/cache.h
+++ b/bin/varnishd/cache/cache.h
@@ -228,9 +228,9 @@ struct http_conn {
/*--------------------------------------------------------------------*/
-struct acct {
+struct acct_req {
#define ACCT(foo) uint64_t foo;
-#include "tbl/acct_fields.h"
+#include "tbl/acct_fields_req.h"
#undef ACCT
};
@@ -654,9 +654,9 @@ struct req {
double d_ttl;
unsigned char wantbody;
- uint64_t req_bodybytes;
+ uint64_t req_bodybytes; /* Parsed req bodybytes */
- uint64_t resp_bodybytes;
+ uint64_t resp_hdrbytes; /* Scheduled resp hdrbytes */
uint16_t err_code;
const char *err_reason;
@@ -716,7 +716,7 @@ struct req {
struct vsl_log vsl[1];
/* Temporary accounting */
- struct acct acct_req;
+ struct acct_req acct;
/* Synth content in vcl_error */
struct vsb *synth_body;
@@ -847,6 +847,7 @@ int HTTP1_CacheReqBody(struct req *req, ssize_t maxsize);
int HTTP1_IterateReqBody(struct req *req, req_body_iter_f *func, void *priv);
/* cache_http1_deliver.c */
+unsigned V1D_FlushReleaseAcct(struct req *req);
void V1D_Deliver(struct req *);
void V1D_Deliver_Synth(struct req *req);
@@ -892,6 +893,7 @@ VDP_pop(struct req *req, vdp_bytes *func)
/* cache_req_fsm.c [CNT] */
enum req_fsm_nxt CNT_Request(struct worker *, struct req *);
+void CNT_AcctLogCharge(struct dstat *, struct req *);
/* cache_cli.c [CLI] */
void CLI_Init(void);
@@ -1099,14 +1101,13 @@ void WRW_Chunked(const struct worker *w);
void WRW_EndChunk(const struct worker *w);
void WRW_Reserve(struct worker *w, int *fd, struct vsl_log *, double t0);
unsigned WRW_Flush(const struct worker *w);
-unsigned WRW_FlushRelease(struct worker *w);
+unsigned WRW_FlushRelease(struct worker *w, ssize_t *pacc);
unsigned WRW_Write(const struct worker *w, const void *ptr, int len);
unsigned WRW_WriteH(const struct worker *w, const txt *hh, const char *suf);
/* cache_session.c [SES] */
void SES_Close(struct sess *sp, enum sess_close reason);
void SES_Delete(struct sess *sp, enum sess_close reason, double now);
-void SES_Charge(struct worker *, struct req *);
struct sesspool *SES_NewPool(struct pool *pp, unsigned pool_no);
void SES_DeletePool(struct sesspool *sp);
int SES_ScheduleReq(struct req *);
diff --git a/bin/varnishd/cache/cache_cli.c b/bin/varnishd/cache/cache_cli.c
index 8aa022b..ca9da16 100644
--- a/bin/varnishd/cache/cache_cli.c
+++ b/bin/varnishd/cache/cache_cli.c
@@ -126,7 +126,7 @@ cli_debug_sizeof(struct cli *cli, const char * const *av, void *priv)
SZOF(struct ws);
SZOF(struct http);
SZOF(struct http_conn);
- SZOF(struct acct);
+ SZOF(struct acct_req);
SZOF(struct worker);
SZOF(struct wrk_accept);
SZOF(struct storage);
diff --git a/bin/varnishd/cache/cache_esi_deliver.c b/bin/varnishd/cache/cache_esi_deliver.c
index b1c3362..dbbe7b1 100644
--- a/bin/varnishd/cache/cache_esi_deliver.c
+++ b/bin/varnishd/cache/cache_esi_deliver.c
@@ -55,7 +55,7 @@ ved_include(struct req *preq, const char *src, const char *host)
if (preq->esi_level >= cache_param->max_esi_depth)
return;
- (void)WRW_FlushRelease(wrk);
+ (void)V1D_FlushReleaseAcct(preq);
/* Take a workspace snapshot */
wrk_ws_wm = WS_Snapshot(wrk->aws); /* XXX ? */
@@ -120,9 +120,17 @@ ved_include(struct req *preq, const char *src, const char *host)
AZ(req->wrk);
(void)usleep(10000);
}
+ AN(WRW_IsReleased(wrk));
- /* Make sure the VSL id has been released */
- AZ(req->vsl->wid);
+ /* Flush and release the log */
+ AN(req->vsl->wid);
+ VSLb(req->vsl, SLT_End, "%s", "");
+ VSL_Flush(req->vsl, 0);
+ req->vsl->wid = 0;
+
+ /* Charge the transmitted body byte counts to the parent request */
+ preq->acct.resp_bodybytes += req->acct.resp_bodybytes;
+ req->acct.resp_bodybytes = 0;
/* Reset the workspace */
WS_Reset(wrk->aws, wrk_ws_wm); /* XXX ? */
diff --git a/bin/varnishd/cache/cache_hash.c b/bin/varnishd/cache/cache_hash.c
index 6cb2de8..1530937 100644
--- a/bin/varnishd/cache/cache_hash.c
+++ b/bin/varnishd/cache/cache_hash.c
@@ -501,7 +501,6 @@ HSH_Lookup(struct req *req, struct objcore **ocp, struct objcore **bocp,
}
wrk->stats.busy_sleep++;
- SES_Charge(wrk, req);
/*
* The objhead reference transfers to the sess, we get it
* back when the sess comes off the waiting list and
diff --git a/bin/varnishd/cache/cache_http1_deliver.c b/bin/varnishd/cache/cache_http1_deliver.c
index e82ed31..5e99668 100644
--- a/bin/varnishd/cache/cache_http1_deliver.c
+++ b/bin/varnishd/cache/cache_http1_deliver.c
@@ -46,8 +46,6 @@ v1d_bytes(struct req *req, enum vdp_action act, const void *ptr, ssize_t len)
if (len > 0)
wl = WRW_Write(req->wrk, ptr, len);
- if (wl > 0)
- req->acct_req.bodybytes += wl;
if (act > VDP_NULL && WRW_Flush(req->wrk))
return (-1);
if (len != wl)
@@ -193,6 +191,33 @@ v1d_WriteDirObj(struct req *req)
return (ois);
}
+/*--------------------------------------------------------------------
+ * V1D_FlushReleaseAcct()
+ * Call WRW_FlushRelease on the worker and update the requests
+ * byte accounting with the number of bytes transmitted
+ *
+ * Returns the return value from WRW_FlushRelease()
+ */
+unsigned
+V1D_FlushReleaseAcct(struct req *req)
+{
+ unsigned u;
+ ssize_t txcnt = 0, hdrbytes;
+
+ CHECK_OBJ_NOTNULL(req, REQ_MAGIC);
+ CHECK_OBJ_NOTNULL(req->wrk, WORKER_MAGIC);
+ u = WRW_FlushRelease(req->wrk, &txcnt);
+ if (req->acct.resp_hdrbytes < req->resp_hdrbytes) {
+ hdrbytes = req->resp_hdrbytes - req->acct.resp_hdrbytes;
+ if (hdrbytes > txcnt)
+ hdrbytes = txcnt;
+ } else
+ hdrbytes = 0;
+ req->acct.resp_hdrbytes += hdrbytes;
+ req->acct.resp_bodybytes += txcnt - hdrbytes;
+ return (u);
+}
+
void
V1D_Deliver(struct req *req)
{
@@ -288,7 +313,7 @@ V1D_Deliver(struct req *req)
* Send HTTP protocol header, unless interior ESI object
*/
if (!(req->res_mode & RES_ESI_CHILD))
- req->acct_req.hdrbytes += HTTP1_Write(req->wrk, req->resp, 1);
+ req->resp_hdrbytes += HTTP1_Write(req->wrk, req->resp, 1);
if (req->res_mode & RES_CHUNKED)
WRW_Chunked(req->wrk);
@@ -320,7 +345,7 @@ V1D_Deliver(struct req *req)
!(req->res_mode & RES_ESI_CHILD))
WRW_EndChunk(req->wrk);
- if ((WRW_FlushRelease(req->wrk) || ois != OIS_DONE) && req->sp->fd >= 0)
+ if ((V1D_FlushReleaseAcct(req) || ois != OIS_DONE) && req->sp->fd >= 0)
SES_Close(req->sp, SC_REM_CLOSE);
}
@@ -395,7 +420,7 @@ V1D_Deliver_Synth(struct req *req)
* Send HTTP protocol header, unless interior ESI object
*/
if (!(req->res_mode & RES_ESI_CHILD))
- req->acct_req.hdrbytes += HTTP1_Write(req->wrk, req->resp, 1);
+ req->resp_hdrbytes += HTTP1_Write(req->wrk, req->resp, 1);
if (req->res_mode & RES_CHUNKED)
WRW_Chunked(req->wrk);
@@ -418,6 +443,6 @@ V1D_Deliver_Synth(struct req *req)
if (req->res_mode & RES_CHUNKED && !(req->res_mode & RES_ESI_CHILD))
WRW_EndChunk(req->wrk);
- if (WRW_FlushRelease(req->wrk) && req->sp->fd >= 0)
+ if (V1D_FlushReleaseAcct(req) && req->sp->fd >= 0)
SES_Close(req->sp, SC_REM_CLOSE);
}
diff --git a/bin/varnishd/cache/cache_http1_fetch.c b/bin/varnishd/cache/cache_http1_fetch.c
index 317bfcb..82dcab6 100644
--- a/bin/varnishd/cache/cache_http1_fetch.c
+++ b/bin/varnishd/cache/cache_http1_fetch.c
@@ -330,7 +330,7 @@ V1F_fetch_hdr(struct worker *wrk, struct busyobj *bo, struct req *req)
}
}
- if (WRW_FlushRelease(wrk) || i != 0) {
+ if (WRW_FlushRelease(wrk, NULL) || i != 0) {
VSLb(bo->vsl, SLT_FetchError, "backend write error: %d (%s)",
errno, strerror(errno));
VSLb_ts_busyobj(bo, "Bereq", W_TIM_real(wrk));
diff --git a/bin/varnishd/cache/cache_http1_fsm.c b/bin/varnishd/cache/cache_http1_fsm.c
index 37ed35a..a46534c 100644
--- a/bin/varnishd/cache/cache_http1_fsm.c
+++ b/bin/varnishd/cache/cache_http1_fsm.c
@@ -126,6 +126,7 @@ http1_wait(struct sess *sp, struct worker *wrk, struct req *req)
VSLb_ts_req(req, "Start", now);
VSLb_ts_req(req, "Req", now);
req->t_req = req->t_prev;
+ req->acct.req_hdrbytes += Tlen(req->htc->rxbuf);
return (REQ_FSM_MORE);
} else if (hs == HTTP1_ERROR_EOF) {
why = SC_REM_CLOSE;
@@ -161,6 +162,8 @@ http1_wait(struct sess *sp, struct worker *wrk, struct req *req)
}
}
}
+ req->acct.req_hdrbytes += Tlen(req->htc->rxbuf);
+ CNT_AcctLogCharge(&wrk->stats, req);
SES_ReleaseReq(req);
assert(why != SC_NULL);
SES_Delete(sp, why, now);
@@ -200,20 +203,28 @@ http1_cleanup(struct sess *sp, struct worker *wrk, struct req *req)
req->vcl = NULL;
}
+ /* Charge and log byte counters */
+ AN(req->vsl->wid);
+ CNT_AcctLogCharge(&wrk->stats, req);
+ req->req_bodybytes = 0;
+ req->resp_hdrbytes = 0;
+
+ /* Nuke the VXID. http1_dissect() will allocate a new one when
+ necessary */
+ VSLb(req->vsl, SLT_End, "%s", "");
+ VSL_Flush(req->vsl, 0);
+ req->vsl->wid = 0;
+
if (!isnan(req->t_prev) && req->t_prev > 0.)
sp->t_idle = req->t_prev;
else
sp->t_idle = W_TIM_real(wrk);
- VSL_Flush(req->vsl, 0);
req->t_first = NAN;
req->t_prev = NAN;
req->t_req = NAN;
req->req_body_status = REQ_BODY_INIT;
- // req->req_bodybytes = 0;
- req->resp_bodybytes = 0;
-
req->hash_always_miss = 0;
req->hash_ignore_busy = 0;
@@ -235,10 +246,17 @@ http1_cleanup(struct sess *sp, struct worker *wrk, struct req *req)
WS_Reset(wrk->aws, NULL);
if (HTTP1_Reinit(req->htc) == HTTP1_COMPLETE) {
+ AZ(req->vsl->wid);
+ req->vsl->wid = VXID_Get(&wrk->vxid_pool) | VSL_CLIENTMARKER;
+ VSLb(req->vsl, SLT_Begin, "req %u rxreq",
+ req->sp->vxid & VSL_IDENTMASK);
+ VSL(SLT_Link, req->sp->vxid, "req %u rxreq",
+ req->vsl->wid & VSL_IDENTMASK);
VSLb_ts_req(req, "Start", sp->t_idle);
VSLb_ts_req(req, "Req", sp->t_idle);
req->t_req = req->t_prev;
wrk->stats.sess_pipeline++;
+ req->acct.req_hdrbytes += Tlen(req->htc->rxbuf);
return (SESS_DONE_RET_START);
} else {
if (Tlen(req->htc->rxbuf))
@@ -285,6 +303,7 @@ http1_dissect(struct worker *wrk, struct req *req)
const char *r_411 = "HTTP/1.1 411 Length Required\r\n\r\n";
const char *r_417 = "HTTP/1.1 417 Expectation Failed\r\n\r\n";
char *p;
+ ssize_t r;
CHECK_OBJ_NOTNULL(wrk, WORKER_MAGIC);
CHECK_OBJ_NOTNULL(req, REQ_MAGIC);
@@ -314,7 +333,9 @@ http1_dissect(struct worker *wrk, struct req *req)
/* If we could not even parse the request, just close */
if (req->err_code != 0) {
wrk->stats.client_req_400++;
- (void)write(req->sp->fd, r_400, strlen(r_400));
+ r = write(req->sp->fd, r_400, strlen(r_400));
+ if (r > 0)
+ req->acct.resp_hdrbytes += r;
SES_Close(req->sp, SC_RX_JUNK);
return (REQ_FSM_DONE);
}
@@ -326,7 +347,9 @@ http1_dissect(struct worker *wrk, struct req *req)
if (req->req_body_status == REQ_BODY_FAIL) {
wrk->stats.client_req_411++;
- (void)write(req->sp->fd, r_411, strlen(r_411));
+ r = write(req->sp->fd, r_411, strlen(r_411));
+ if (r > 0)
+ req->acct.resp_hdrbytes += r;
SES_Close(req->sp, SC_RX_JUNK);
return (REQ_FSM_DONE);
}
@@ -335,21 +358,25 @@ http1_dissect(struct worker *wrk, struct req *req)
if (strcasecmp(p, "100-continue")) {
wrk->stats.client_req_417++;
req->err_code = 417;
- (void)write(req->sp->fd, r_417, strlen(r_417));
+ r = write(req->sp->fd, r_417, strlen(r_417));
+ if (r > 0)
+ req->resp_hdrbytes += r;
SES_Close(req->sp, SC_RX_JUNK);
return (REQ_FSM_DONE);
}
- if (strlen(r_100) != write(req->sp->fd, r_100, strlen(r_100))) {
- // XXX: stats counter ?
+ r = write(req->sp->fd, r_100, strlen(r_100));
+ if (r > 0)
+ req->acct.resp_hdrbytes += r;
+ if (r != strlen(r_100)) {
SES_Close(req->sp, SC_REM_CLOSE);
return (REQ_FSM_DONE);
}
}
wrk->stats.client_req++;
+ wrk->stats.s_req++;
AZ(req->err_code);
- req->acct_req.req++;
req->ws_req = WS_Snapshot(req->ws);
req->doclose = http_DoConnection(req->http);
@@ -475,6 +502,7 @@ http1_iter_req_body(struct req *req, void *buf, ssize_t len)
}
req->h1.bytes_done += len;
req->h1.bytes_yet = req->req_bodybytes - req->h1.bytes_done;
+ req->acct.req_bodybytes += len;
return (len);
}
diff --git a/bin/varnishd/cache/cache_pipe.c b/bin/varnishd/cache/cache_pipe.c
index 1a0a44f..7d77096 100644
--- a/bin/varnishd/cache/cache_pipe.c
+++ b/bin/varnishd/cache/cache_pipe.c
@@ -66,6 +66,7 @@ PipeRequest(struct req *req, struct busyobj *bo)
struct worker *wrk;
struct pollfd fds[2];
int i;
+ ssize_t txcnt;
CHECK_OBJ_NOTNULL(req, REQ_MAGIC);
CHECK_OBJ_NOTNULL(req->sp, SESS_MAGIC);
@@ -80,14 +81,13 @@ PipeRequest(struct req *req, struct busyobj *bo)
(void)VTCP_blocking(vc->fd);
WRW_Reserve(wrk, &vc->fd, bo->vsl, req->t_req);
- req->acct_req.hdrbytes += HTTP1_Write(wrk, bo->bereq, 0);
+ (void)HTTP1_Write(wrk, bo->bereq, 0);
if (req->htc->pipeline.b != NULL)
- req->acct_req.bodybytes +=
- WRW_Write(wrk, req->htc->pipeline.b,
+ (void)WRW_Write(wrk, req->htc->pipeline.b,
Tlen(req->htc->pipeline));
- i = WRW_FlushRelease(wrk);
+ i = WRW_FlushRelease(wrk, &txcnt);
VSLb_ts_req(req, "Pipe", W_TIM_real(wrk));
diff --git a/bin/varnishd/cache/cache_req_fsm.c b/bin/varnishd/cache/cache_req_fsm.c
index 090e0b6..8888226 100644
--- a/bin/varnishd/cache/cache_req_fsm.c
+++ b/bin/varnishd/cache/cache_req_fsm.c
@@ -200,7 +200,7 @@ cnt_synth(struct worker *wrk, struct req *req)
CHECK_OBJ_NOTNULL(wrk, WORKER_MAGIC);
CHECK_OBJ_NOTNULL(req, REQ_MAGIC);
- req->acct_req.synth++;
+ wrk->stats.s_synth++;
HTTP_Setup(req->resp, req->ws, req->vsl, SLT_RespMethod);
h = req->resp;
@@ -281,7 +281,7 @@ cnt_fetch(struct worker *wrk, struct req *req)
CHECK_OBJ_NOTNULL(req->objcore, OBJCORE_MAGIC);
AZ(req->obj);
- req->acct_req.fetch++;
+ wrk->stats.s_fetch++;
(void)HTTP1_DiscardReqBody(req);
if (req->objcore->flags & OC_F_FAILED) {
@@ -554,7 +554,7 @@ cnt_pass(struct worker *wrk, struct req *req)
req->req_step = R_STP_RESTART;
break;
case VCL_RET_FETCH:
- req->acct_req.pass++;
+ wrk->stats.s_pass++;
req->objcore = HSH_Private(wrk);
CHECK_OBJ_NOTNULL(req->objcore, OBJCORE_MAGIC);
VBF_Fetch(wrk, req, req->objcore, NULL, VBF_PASS);
@@ -593,7 +593,7 @@ cnt_pipe(struct worker *wrk, struct req *req)
CHECK_OBJ_NOTNULL(req, REQ_MAGIC);
CHECK_OBJ_NOTNULL(req->vcl, VCL_CONF_MAGIC);
- req->acct_req.pipe++;
+ wrk->stats.s_pipe++;
bo = VBO_GetBusyObj(wrk, req);
HTTP_Setup(bo->bereq, bo->ws, bo->vsl, SLT_BereqMethod);
http_FilterReq(bo->bereq, req->http, 0); // XXX: 0 ?
@@ -897,33 +897,43 @@ CNT_Request(struct worker *wrk, struct req *req)
}
if (nxt == REQ_FSM_DONE) {
/* XXX: Workaround for pipe */
- if (req->sp->fd >= 0) {
- VSLb(req->vsl, SLT_Length, "%ju",
- (uintmax_t)req->resp_bodybytes);
- }
while (!VTAILQ_EMPTY(&req->body)) {
st = VTAILQ_FIRST(&req->body);
VTAILQ_REMOVE(&req->body, st, list);
STV_free(st);
}
-
- /* done == 2 was charged by cache_hash.c */
- SES_Charge(wrk, req);
-
- /*
- * Nuke the VXID, cache_http1_fsm.c::http1_dissect() will
- * allocate a new one when necessary.
- */
- VSLb(req->vsl, SLT_End, "%s", "");
- req->vsl->wid = 0;
- req->wrk = NULL;
}
-
+ req->wrk = NULL;
assert(WRW_IsReleased(wrk));
return (nxt);
}
+void
+CNT_AcctLogCharge(struct dstat *ds, struct req *req)
+{
+ struct acct_req *a;
+
+ AN(ds);
+ CHECK_OBJ_NOTNULL(req, REQ_MAGIC);
+
+ a = &req->acct;
+
+ VSLb(req->vsl, SLT_ReqAcct, "%ju %ju %ju %ju %ju %ju",
+ (uintmax_t)a->req_hdrbytes,
+ (uintmax_t)a->req_bodybytes,
+ (uintmax_t)(a->req_hdrbytes + a->req_bodybytes),
+ (uintmax_t)a->resp_hdrbytes,
+ (uintmax_t)a->resp_bodybytes,
+ (uintmax_t)(a->resp_hdrbytes + a->resp_bodybytes));
+
+#define ACCT(foo) \
+ ds->s_##foo += a->foo; \
+ a->foo = 0;
+#include "tbl/acct_fields_req.h"
+#undef ACCT
+}
+
/*
DOT }
*/
diff --git a/bin/varnishd/cache/cache_session.c b/bin/varnishd/cache/cache_session.c
index 8059c83..0c5d2f9 100644
--- a/bin/varnishd/cache/cache_session.c
+++ b/bin/varnishd/cache/cache_session.c
@@ -62,31 +62,6 @@ struct sesspool {
};
/*--------------------------------------------------------------------
- * Charge statistics from worker to request and session.
- */
-
-void
-SES_Charge(struct worker *wrk, struct req *req)
-{
- struct sess *sp;
- struct acct *a;
-
- CHECK_OBJ_NOTNULL(wrk, WORKER_MAGIC);
- CHECK_OBJ_NOTNULL(req, REQ_MAGIC);
- sp = req->sp;
- CHECK_OBJ_NOTNULL(sp, SESS_MAGIC);
-
- a = &req->acct_req;
- req->resp_bodybytes += a->bodybytes;
-
-#define ACCT(foo) \
- wrk->stats.s_##foo += a->foo; \
- a->foo = 0;
-#include "tbl/acct_fields.h"
-#undef ACCT
-}
-
-/*--------------------------------------------------------------------
* Get a new session, preferably by recycling an already ready one
*
* Layout is:
@@ -395,6 +370,9 @@ SES_GetReq(struct worker *wrk, struct sess *sp)
WS_Init(req->ws, "req", p, e - p);
+ req->req_bodybytes = 0;
+ req->resp_hdrbytes = 0;
+
req->t_first = NAN;
req->t_prev = NAN;
req->t_req = NAN;
@@ -411,10 +389,14 @@ SES_ReleaseReq(struct req *req)
struct sesspool *pp;
CHECK_OBJ_NOTNULL(req, REQ_MAGIC);
- AZ(req->vcl);
-#define ACCT(foo) AZ(req->acct_req.foo);
-#include "tbl/acct_fields.h"
+
+ /* Make sure the request counters have all been zeroed */
+#define ACCT(foo) \
+ AZ(req->acct.foo);
+#include "tbl/acct_fields_req.h"
#undef ACCT
+
+ AZ(req->vcl);
sp = req->sp;
CHECK_OBJ_NOTNULL(sp, SESS_MAGIC);
pp = sp->sesspool;
diff --git a/bin/varnishd/cache/cache_wrw.c b/bin/varnishd/cache/cache_wrw.c
index adf2f11..a418ea0 100644
--- a/bin/varnishd/cache/cache_wrw.c
+++ b/bin/varnishd/cache/cache_wrw.c
@@ -58,6 +58,7 @@ struct wrw {
unsigned ciov; /* Chunked header marker */
double t0;
struct vsl_log *vsl;
+ ssize_t cnt; /* Flushed byte count */
};
/*--------------------------------------------------------------------
@@ -101,7 +102,7 @@ WRW_Reserve(struct worker *wrk, int *fd, struct vsl_log *vsl, double t0)
}
static void
-WRW_Release(struct worker *wrk)
+wrw_release(struct worker *wrk, ssize_t *pacc)
{
struct wrw *wrw;
@@ -109,6 +110,8 @@ WRW_Release(struct worker *wrk)
wrw = wrk->wrw;
wrk->wrw = NULL;
CHECK_OBJ_NOTNULL(wrw, WRW_MAGIC);
+ if (pacc != NULL)
+ *pacc += wrw->cnt;
WS_Release(wrk->aws, 0);
WS_Reset(wrk->aws, NULL);
}
@@ -171,6 +174,8 @@ WRW_Flush(const struct worker *wrk)
}
i = writev(*wrw->wfd, wrw->iov, wrw->niov);
+ if (i > 0)
+ wrw->cnt += i;
while (i != wrw->liov && i > 0) {
/* Remove sent data from start of I/O vector,
* then retry; we hit a timeout, but some data
@@ -195,6 +200,8 @@ WRW_Flush(const struct worker *wrk)
wrw_prune(wrw, i);
i = writev(*wrw->wfd, wrw->iov, wrw->niov);
+ if (i > 0)
+ wrw->cnt += i;
}
if (i <= 0) {
wrw->werr++;
@@ -212,14 +219,14 @@ WRW_Flush(const struct worker *wrk)
}
unsigned
-WRW_FlushRelease(struct worker *wrk)
+WRW_FlushRelease(struct worker *wrk, ssize_t *pacc)
{
unsigned u;
CHECK_OBJ_NOTNULL(wrk, WORKER_MAGIC);
AN(wrk->wrw->wfd);
u = WRW_Flush(wrk);
- WRW_Release(wrk);
+ wrw_release(wrk, pacc);
return (u);
}
diff --git a/bin/varnishtest/tests/l00002.vtc b/bin/varnishtest/tests/l00002.vtc
new file mode 100644
index 0000000..0106324
--- /dev/null
+++ b/bin/varnishtest/tests/l00002.vtc
@@ -0,0 +1,108 @@
+varnishtest "Test request byte counters"
+
+server s1 {
+ rxreq
+ expect req.url == "/1"
+ txresp -bodylen 1000
+
+ rxreq
+ expect req.url == "/2"
+ txresp -bodylen 2000
+} -start
+
+varnish v1 -vcl+backend {
+ sub vcl_deliver {
+ unset resp.http.date;
+ unset resp.http.age;
+ unset resp.http.via;
+ unset resp.http.x-varnish;
+ }
+} -start
+
+# Request (1001):
+# GET /1 HTTP/1.1\r\n 17 bytes
+# Content-Length: 4\r\n 19 bytes
+# \r\n 2 bytes
+# Total: 38 bytes
+# Response:
+# HTTP/1.1 200 Ok\r\n 17 bytes
+# Content-Length: 1000\r\n 22 bytes
+# Connection: keep-alive\r\n 24 bytes
+# Accept-Ranges: bytes\r\n 22 bytes
+# \r\n 2 bytes
+# Total: 87 bytes
+
+# Request (1003):
+# GET /2 HTTP/1.1\r\n 17 bytes
+# \r\n 2 bytes
+# Total: 19 bytes
+# Response:
+# HTTP/1.1 200 Ok\r\n 17 bytes
+# Content-Length: 2000\r\n 22 bytes
+# Connection: keep-alive\r\n 24 bytes
+# Accept-Ranges: bytes\r\n 22 bytes
+# \r\n 2 bytes
+# Total: 87 bytes
+
+# Request (1005):
+# GET /2 HTTP/1.1\r\n 17 bytes
+# \r\n 2 bytes
+# Total: 19 bytes
+# Response:
+# HTTP/1.1 200 Ok\r\n 17 bytes
+# Content-Length: 2000\r\n 22 bytes
+# Connection: keep-alive\r\n 24 bytes
+# Accept-Ranges: bytes\r\n 22 bytes
+# \r\n 2 bytes
+# Total: 87 bytes
+
+# Request (1006):
+# GET\r\n 5 bytes
+# \r\n 2 bytes
+# Total: 7 bytes
+# Response:
+# HTTP/1.1 400 Bad Request\r\n 26 bytes
+# \r\n 2 bytes
+# Total: 28 bytes
+logexpect l1 -v v1 -g request {
+ expect 0 1001 Begin "^req .* rxreq"
+ expect * = ReqAcct "^38 4 42 87 1000 1087$"
+ expect 0 = End
+ expect 0 1002 Begin "^bereq "
+ expect * = End
+ expect 0 1003 Begin "^req .* rxreq"
+ expect * = ReqAcct "^19 0 19 87 2000 2087$"
+ expect 0 = End
+ expect 0 1004 Begin "^bereq"
+ expect * = End
+ expect 0 1005 Begin "^req .* rxreq"
+ expect * = ReqAcct "^19 0 19 87 2000 2087$"
+ expect 0 = End
+ expect 0 1006 Begin "^req .* rxreq"
+ expect * = ReqAcct "^7 0 7 28 0 28$"
+ expect 0 = End
+} -start
+
+# Request 1001
+client c1 {
+ txreq -url "/1" -body "asdf"
+ rxresp
+ expect resp.status == 200
+
+ send "GET /2 HTTP/1.1\r\n\r\nGET /2 HTTP/1.1\r\n\r\n"
+ rxresp
+ expect resp.status == 200
+ rxresp
+ expect resp.status == 200
+
+ send "GET\r\n\r\n"
+ rxresp
+ expect resp.status == 400
+} -run
+
+logexpect l1 -wait
+
+varnish v1 -expect s_req_hdrbytes == 83
+varnish v1 -expect s_req_bodybytes == 4
+varnish v1 -expect s_resp_hdrbytes == 289
+varnish v1 -expect s_resp_bodybytes == 5000
diff --git a/include/Makefile.am b/include/Makefile.am
index 3813836..e996fc0 100644
--- a/include/Makefile.am
+++ b/include/Makefile.am
@@ -2,7 +2,7 @@
# API headers
nobase_pkginclude_HEADERS = \
- tbl/acct_fields.h \
+ tbl/acct_fields_req.h \
tbl/backend_poll.h \
tbl/ban_vars.h \
tbl/bo_flags.h \
diff --git a/include/tbl/acct_fields.h b/include/tbl/acct_fields.h
deleted file mode 100644
index ac205a7..0000000
--- a/include/tbl/acct_fields.h
+++ /dev/null
@@ -1,40 +0,0 @@
-/*-
- * Copyright (c) 2008 Verdens Gang AS
- * Copyright (c) 2008-2009 Varnish Software AS
- * All rights reserved.
- *
- * Author: Poul-Henning Kamp <phk at phk.freebsd.dk>
- *
- * Redistribution and use in source and binary forms, with or without
- * modification, are permitted provided that the following conditions
- * are met:
- * 1. Redistributions of source code must retain the above copyright
- * notice, this list of conditions and the following disclaimer.
- * 2. Redistributions in binary form must reproduce the above copyright
- * notice, this list of conditions and the following disclaimer in the
- * documentation and/or other materials provided with the distribution.
- *
- * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
- * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
- * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
- * ARE DISCLAIMED. IN NO EVENT SHALL AUTHOR OR CONTRIBUTORS BE LIABLE
- * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
- * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
- * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
- * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
- * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
- * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
- * SUCH DAMAGE.
- *
- * These are the stats we keep track of per session.
- * SES_Charge() sums them into wrk->stats
- * NB: Remember to mark those in vsc_fields.h to be included in struct dstat.
- */
-
-ACCT(req)
-ACCT(pipe)
-ACCT(pass)
-ACCT(fetch)
-ACCT(synth)
-ACCT(hdrbytes)
-ACCT(bodybytes)
diff --git a/include/tbl/acct_fields_req.h b/include/tbl/acct_fields_req.h
new file mode 100644
index 0000000..a1759f5
--- /dev/null
+++ b/include/tbl/acct_fields_req.h
@@ -0,0 +1,36 @@
+/*-
+ * Copyright (c) 2008 Verdens Gang AS
+ * Copyright (c) 2008-2014 Varnish Software AS
+ * All rights reserved.
+ *
+ * Author: Poul-Henning Kamp <phk at phk.freebsd.dk>
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions
+ * are met:
+ * 1. Redistributions of source code must retain the above copyright
+ * notice, this list of conditions and the following disclaimer.
+ * 2. Redistributions in binary form must reproduce the above copyright
+ * notice, this list of conditions and the following disclaimer in the
+ * documentation and/or other materials provided with the distribution.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
+ * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
+ * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
+ * ARE DISCLAIMED. IN NO EVENT SHALL AUTHOR OR CONTRIBUTORS BE LIABLE
+ * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
+ * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
+ * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
+ * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
+ * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
+ * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
+ * SUCH DAMAGE.
+ *
+ * These are the stats we keep track of per request.
+ * NB: Remember to mark those in vsc_fields.h to be included in struct dstat.
+ */
+
+ACCT(req_hdrbytes)
+ACCT(req_bodybytes)
+ACCT(resp_hdrbytes)
+ACCT(resp_bodybytes)
diff --git a/include/tbl/vsc_f_main.h b/include/tbl/vsc_f_main.h
index 3874ec1..859a2eb 100644
--- a/include/tbl/vsc_f_main.h
+++ b/include/tbl/vsc_f_main.h
@@ -384,13 +384,21 @@ VSC_F(s_synth, uint64_t, 1, 'a', info,
"Total synth",
""
)
-VSC_F(s_hdrbytes, uint64_t, 1, 'a', info,
- "Total header bytes",
- ""
+VSC_F(s_req_hdrbytes, uint64_t, 1, 'a', info,
+ "Request header bytes",
+ "Total request header bytes received"
)
-VSC_F(s_bodybytes, uint64_t, 1, 'a', info,
- "Total body bytes",
- ""
+VSC_F(s_req_bodybytes, uint64_t, 1, 'a', info,
+ "Request body bytes",
+ "Total request body bytes received"
+)
+VSC_F(s_resp_hdrbytes, uint64_t, 1, 'a', info,
+ "Response header bytes",
+ "Total response header bytes transmitted"
+)
+VSC_F(s_resp_bodybytes, uint64_t, 1, 'a', info,
+ "Reponse body bytes",
+ "Total response body bytes transmitted"
)
VSC_F(sess_closed, uint64_t, 1, 'a', info,
diff --git a/include/tbl/vsl_tags.h b/include/tbl/vsl_tags.h
index 10a3a15..252b859 100644
--- a/include/tbl/vsl_tags.h
+++ b/include/tbl/vsl_tags.h
@@ -474,4 +474,18 @@ SLTM(Timestamp, 0, "Timing information",
"\n"
)
+SLTM(ReqAcct, 0, "Request handling byte counts",
+ "Contains byte counts for the request handling.\n\n"
+ "The format is::\n\n"
+ "\t%d %d %d %d %d %d\n"
+ "\t| | | | | |\n"
+ "\t| | | | | +- Total bytes transmitted\n"
+ "\t| | | | +---- Body bytes transmitted\n"
+ "\t| | | +------- Header bytes transmitted\n"
+ "\t| | +---------- Total bytes received\n"
+ "\t| +------------- Body bytes received\n"
+ "\t+---------------- Header bytes received\n"
+ "\n"
+)
+
#undef NODEF_NOTICE
More information about the varnish-commit
mailing list