[master] f1e4277 Overhaul request accounting, particularly for ESI.
Poul-Henning Kamp
phk at FreeBSD.org
Wed Oct 22 13:11:25 CEST 2014
commit f1e42779fa318d4a21eb349195c89f4705aeebab
Author: Poul-Henning Kamp <phk at FreeBSD.org>
Date: Wed Oct 22 10:14:19 2014 +0000
Overhaul request accounting, particularly for ESI.
Give ESI subrequests a ReqAcct.
Make the bodycount in ReqAcct only the actual body, not including
transmission overhead (such as chunked encoding)
diff --git a/bin/varnishd/cache/cache.h b/bin/varnishd/cache/cache.h
index 0e9668e..3ba86b7 100644
--- a/bin/varnishd/cache/cache.h
+++ b/bin/varnishd/cache/cache.h
@@ -557,9 +557,6 @@ struct req {
unsigned char wantbody;
uint64_t req_bodybytes; /* Parsed req bodybytes */
- uint64_t resp_hdrbytes; /* Scheduled resp hdrbytes */
- uint64_t resp_bodybytes; /* Scheduled resp bodybytes */
-
uint16_t err_code;
const char *err_reason;
@@ -721,7 +718,6 @@ extern const int HTTP1_Req[3];
extern const int HTTP1_Resp[3];
/* cache_http1_deliver.c */
-unsigned V1D_FlushReleaseAcct(struct req *req);
void V1D_Deliver(struct req *, struct busyobj *);
/* cache_http1_pipe.c */
diff --git a/bin/varnishd/cache/cache_esi_deliver.c b/bin/varnishd/cache/cache_esi_deliver.c
index 06e2570..2663c7d 100644
--- a/bin/varnishd/cache/cache_esi_deliver.c
+++ b/bin/varnishd/cache/cache_esi_deliver.c
@@ -56,7 +56,7 @@ ved_include(struct req *preq, const char *src, const char *host)
if (preq->esi_level >= cache_param->max_esi_depth)
return;
- (void)V1D_FlushReleaseAcct(preq);
+ (void)WRW_FlushRelease(preq->wrk, NULL);
/* Take a workspace snapshot */
wrk_ws_wm = WS_Snapshot(wrk->aws); /* XXX ? */
@@ -132,11 +132,11 @@ ved_include(struct req *preq, const char *src, const char *host)
}
AN(WRW_IsReleased(wrk));
- VSL_End(req->vsl);
-
- /* Charge the transmitted body byte counts to the parent request */
+ /* Charge the transmitted body byte counts also to the parent request */
preq->acct.resp_bodybytes += req->acct.resp_bodybytes;
- req->acct.resp_bodybytes = 0;
+
+ CNT_AcctLogCharge(wrk->stats, req);
+ VSL_End(req->vsl);
/* Reset the workspace */
WS_Reset(wrk->aws, wrk_ws_wm); /* XXX ? */
diff --git a/bin/varnishd/cache/cache_req_fsm.c b/bin/varnishd/cache/cache_req_fsm.c
index 9c2627a..48e894d 100644
--- a/bin/varnishd/cache/cache_req_fsm.c
+++ b/bin/varnishd/cache/cache_req_fsm.c
@@ -791,10 +791,6 @@ CNT_Request(struct worker *wrk, struct req *req)
wrk->vsl = NULL;
if (nxt == REQ_FSM_DONE) {
AN(req->vsl->wid);
- if (req->res_mode & (RES_ESI|RES_ESI_CHILD))
- VSLb(req->vsl, SLT_ESI_BodyBytes, "%ju",
- (uintmax_t)req->resp_bodybytes);
-
VRB_Free(req);
req->wrk = NULL;
}
diff --git a/bin/varnishd/cache/cache_session.c b/bin/varnishd/cache/cache_session.c
index 04a4ca5..5d5b289 100644
--- a/bin/varnishd/cache/cache_session.c
+++ b/bin/varnishd/cache/cache_session.c
@@ -366,8 +366,6 @@ SES_GetReq(const struct worker *wrk, struct sess *sp)
WS_Init(req->ws, "req", p, e - p);
req->req_bodybytes = 0;
- req->resp_hdrbytes = 0;
- req->resp_bodybytes = 0;
req->t_first = NAN;
req->t_prev = NAN;
diff --git a/bin/varnishd/http1/cache_http1_deliver.c b/bin/varnishd/http1/cache_http1_deliver.c
index 05be1f1..cde97b5 100644
--- a/bin/varnishd/http1/cache_http1_deliver.c
+++ b/bin/varnishd/http1/cache_http1_deliver.c
@@ -51,7 +51,7 @@ v1d_bytes(struct req *req, enum vdp_action act, void **priv,
if (len > 0)
wl = WRW_Write(req->wrk, ptr, len);
- req->resp_bodybytes += wl;
+ req->acct.resp_bodybytes += len;
if (act > VDP_NULL && WRW_Flush(req->wrk))
return (-1);
if (len != wl)
@@ -228,33 +228,6 @@ v1d_WriteDirObj(struct req *req)
}
/*--------------------------------------------------------------------
- * 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;
- uint64_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, struct busyobj *bo)
@@ -360,7 +333,7 @@ V1D_Deliver(struct req *req, struct busyobj *bo)
* Send HTTP protocol header, unless interior ESI object
*/
if (!(req->res_mode & RES_ESI_CHILD))
- req->resp_hdrbytes +=
+ req->acct.resp_hdrbytes +=
HTTP1_Write(req->wrk, req->resp, HTTP1_Resp);
if (req->res_mode & RES_CHUNKED)
@@ -408,6 +381,7 @@ V1D_Deliver(struct req *req, struct busyobj *bo)
!(req->res_mode & RES_ESI_CHILD))
WRW_EndChunk(req->wrk);
- if ((V1D_FlushReleaseAcct(req) || ois != OIS_DONE) && req->sp->fd >= 0)
+ if ((WRW_FlushRelease(req->wrk, NULL) || ois != OIS_DONE) &&
+ req->sp->fd >= 0)
SES_Close(req->sp, SC_REM_CLOSE);
}
diff --git a/bin/varnishd/http1/cache_http1_fsm.c b/bin/varnishd/http1/cache_http1_fsm.c
index 4850df2..1737e65 100644
--- a/bin/varnishd/http1/cache_http1_fsm.c
+++ b/bin/varnishd/http1/cache_http1_fsm.c
@@ -171,8 +171,6 @@ http1_cleanup(struct sess *sp, struct worker *wrk, struct req *req)
AN(req->vsl->wid);
CNT_AcctLogCharge(wrk->stats, req);
req->req_bodybytes = 0;
- req->resp_hdrbytes = 0;
- req->resp_bodybytes = 0;
VSL_End(req->vsl);
@@ -285,7 +283,7 @@ http1_dissect(struct worker *wrk, struct req *req)
req->err_code = 417;
r = write(req->sp->fd, r_417, strlen(r_417));
if (r > 0)
- req->resp_hdrbytes += r;
+ req->acct.resp_hdrbytes += r;
SES_Close(req->sp, SC_RX_JUNK);
return (REQ_FSM_DONE);
}
diff --git a/bin/varnishtest/tests/e00003.vtc b/bin/varnishtest/tests/e00003.vtc
index bf61f4f..935e1f0 100644
--- a/bin/varnishtest/tests/e00003.vtc
+++ b/bin/varnishtest/tests/e00003.vtc
@@ -8,6 +8,7 @@ server s1 {
Before include
<esi:include src="/body" sr="foo"/>
After include
+ </html>
}
rxreq
expect req.url == "/body1"
@@ -27,17 +28,41 @@ varnish v1 -vcl+backend {
}
} -start
+logexpect l1 -v v1 -g request {
+ expect 0 1001 Begin "^req .* rxreq"
+ expect * = ReqAcct "^18 0 18 154 75 229$"
+ expect 0 = End
+
+ expect 0 1002 Begin "^bereq "
+ expect * = End
+
+ expect 0 1003 Begin "^req .* esi"
+ expect * = ReqAcct "^0 0 0 0 18 18$"
+ expect 0 = End
+
+ expect 0 1004 Begin "^bereq "
+ expect * = End
+
+ expect 0 1005 Begin "^req .* rxreq"
+ expect * = ReqAcct "^18 0 18 159 75 234$"
+ expect 0 = End
+} -start
+
client c1 {
txreq
rxresp
- expect resp.bodylen == 65
+ expect resp.bodylen == 75
expect resp.status == 200
+
+ delay .1
# test that there is no difference on miss/hit
txreq
rxresp
- expect resp.bodylen == 65
+ expect resp.bodylen == 75
expect resp.status == 200
}
client c1 -run
varnish v1 -expect esi_errors == 0
+
+logexpect l1 -wait
diff --git a/bin/varnishtest/tests/l00003.vtc b/bin/varnishtest/tests/l00003.vtc
index 86c9e2a..851073c 100644
--- a/bin/varnishtest/tests/l00003.vtc
+++ b/bin/varnishtest/tests/l00003.vtc
@@ -39,33 +39,25 @@ varnish v1 -vcl+backend {
# Total: 71 bytes
# Response body:
-# 003\r\n 5 bytes
# 123\r\n 5 bytes
-# 003\r\n 5 bytes
# abc\r\n 5 bytes
-# 003\r\n 5 bytes
# 123\r\n 5 bytes
-# 003\r\n 5 bytes
# def\r\n 5 bytes
-# 003\r\n 5 bytes
# ghi\r\n 5 bytes
-# 0\r\n 3 bytes
-# \r\n 2 bytes
-# Total: 55 bytes
+# Total: 15 bytes
logexpect l1 -v v1 -g request {
expect 0 1001 Begin "^req .* rxreq"
- expect * = ESI_BodyBytes "^3"
- expect * = ReqAcct "^18 0 18 71 55 126$"
+ expect * = ReqAcct "^18 0 18 71 15 86$"
expect 0 = End
expect * 1003 Begin "^req .* esi"
- expect * = ESI_BodyBytes "^6$"
+ expect * = ReqAcct "^0 0 0 0 12 12$"
expect 0 = End
expect * 1005 Begin "^req .* esi"
- expect * = ESI_BodyBytes "^3$"
+ expect * = ReqAcct "^0 0 0 0 3 3$"
expect 0 = End
expect * 1007 Begin "^req .* esi"
- expect * = ESI_BodyBytes "^3$"
+ expect * = ReqAcct "^0 0 0 0 3 3$"
expect 0 = End
} -start
@@ -81,4 +73,4 @@ logexpect l1 -wait
varnish v1 -expect s_req_hdrbytes == 18
varnish v1 -expect s_req_bodybytes == 0
varnish v1 -expect s_resp_hdrbytes == 71
-varnish v1 -expect s_resp_bodybytes == 55
+varnish v1 -expect s_resp_bodybytes == 33
diff --git a/include/tbl/vsl_tags.h b/include/tbl/vsl_tags.h
index 8ca37d0..b483f2c 100644
--- a/include/tbl/vsl_tags.h
+++ b/include/tbl/vsl_tags.h
@@ -444,9 +444,10 @@ SLTM(Timestamp, 0, "Timing information",
)
SLTM(ReqAcct, 0, "Request handling byte counts",
- "Contains byte counts for the request handling. This record is not"
- " logged for ESI sub-requests, but the sub-requests' response"
- " body count is added to the main request.\n\n"
+ "Contains byte counts for the request handling.\n"
+ "ESI sub-request counts are also added to their parent request.\n"
+ "The body bytes count does not include transmission "
+ "(ie: chunked encoding) overhead.\n"
"The format is::\n\n"
"\t%d %d %d %d %d %d\n"
"\t| | | | | |\n"
@@ -459,16 +460,6 @@ SLTM(ReqAcct, 0, "Request handling byte counts",
"\n"
)
-SLTM(ESI_BodyBytes, 0, "ESI body fragment byte counter",
- "Contains the body byte count for this ESI body fragment."
- " This number does not include any transfer encoding overhead.\n\n"
- "The format is::\n\n"
- "\t%d\n"
- "\t|\n"
- "\t+- Body bytes\n"
- "\n"
-)
-
SLTM(PipeAcct, 0, "Pipe byte counts",
"Contains byte counters for pipe sessions.\n\n"
"The format is::\n\n"
More information about the varnish-commit
mailing list