Be more careful about handling the request-body.

bin/varnishd/cache/cache.h

@@ -592,7 +592,7 @@ struct req {
 	struct exp		exp;
 	unsigned		cur_method;
 	unsigned		handling;
-	unsigned char		sendbody;
+	unsigned char		reqbodydone;
 	unsigned char		wantbody;
 
 	uint16_t		err_code;
@@ -765,9 +765,9 @@ int EXP_NukeOne(struct worker *w, struct lru *lru);
 struct storage *FetchStorage(struct worker *w, ssize_t sz);
 int FetchError(struct worker *w, const char *error);
 int FetchError2(struct worker *w, const char *error, const char *more);
-int FetchHdr(struct sess *sp, int need_host_hdr);
+int FetchHdr(struct sess *sp, int need_host_hdr, int sendbody);
 int FetchBody(struct worker *w, struct object *obj);
-int FetchReqBody(const struct sess *sp);
+int FetchReqBody(const struct sess *sp, int sendbody);
 void Fetch_Init(void);
 
 /* cache_gzip.c */

bin/varnishd/cache/cache_acceptor.c

@@ -253,8 +253,6 @@ VCA_SetupSess(struct worker *wrk)
 	sp->vsl_id = wa->acceptsock | VSL_CLIENTMARKER ;
 	wa->acceptsock = -1;
 	sp->t_open = VTIM_real();
-	sp->t_req = sp->t_open;
-	sp->t_idle = sp->t_open;
 	sp->mylsock = wa->acceptlsock;
 	CHECK_OBJ_NOTNULL(sp->mylsock, LISTEN_SOCK_MAGIC);
 	assert(wa->acceptaddrlen <= sp->sockaddrlen);

bin/varnishd/cache/cache_center.c

@@ -83,6 +83,11 @@ static unsigned xids;
  * WAIT
  * Collect the request from the client.
  *
+ * We "abuse" sp->t_req a bit here:  On input it means "request reception
+ * started at xxx" and is used to trigger timeouts.  On return it means
+ * "we had full request headers by xxx" and is used for reporting by
+ * later steps.
+ *
 DOT subgraph xcluster_wait {
 DOT	wait [
 DOT		shape=box
@@ -446,17 +451,16 @@ cnt_done(struct sess *sp, struct worker *wrk, struct req *req)
 	WS_Reset(req->ws, NULL);
 	WS_Reset(wrk->ws, NULL);
 
+	sp->t_req = sp->t_idle;
 	i = HTC_Reinit(req->htc);
 	if (i == 1) {
 		wrk->stats.sess_pipeline++;
-		sp->t_req = sp->t_idle;
 		sp->step = STP_START;
-		return (0);
+	} else {
+		if (Tlen(req->htc->rxbuf))
+			wrk->stats.sess_readahead++;
+		sp->step = STP_WAIT;
 	}
-	if (Tlen(req->htc->rxbuf))
-		wrk->stats.sess_readahead++;
-	sp->step = STP_WAIT;
-	sp->t_req = sp->t_idle;
 	return (0);
 }
 
@@ -597,7 +601,7 @@ cnt_fetch(struct sess *sp, struct worker *wrk, struct req *req)
 
 	need_host_hdr = !http_GetHdr(wrk->busyobj->bereq, H_Host, NULL);
 
-	i = FetchHdr(sp, need_host_hdr);
+	i = FetchHdr(sp, need_host_hdr, req->objcore == NULL);
 	/*
 	 * If we recycle a backend connection, there is a finite chance
 	 * that the backend closed it before we get a request to it.
@@ -605,7 +609,7 @@ cnt_fetch(struct sess *sp, struct worker *wrk, struct req *req)
 	 */
 	if (i == 1) {
 		VSC_C_main->backend_retry++;
-		i = FetchHdr(sp, need_host_hdr);
+		i = FetchHdr(sp, need_host_hdr, req->objcore == NULL);
 	}
 
 	if (i) {
@@ -1042,6 +1046,8 @@ cnt_first(struct sess *sp, struct worker *wrk)
 
 	wrk->acct_tmp.sess++;
 
+	sp->t_req = sp->t_open;
+	sp->t_idle = sp->t_open;
 	sp->step = STP_WAIT;
 	return (0);
 }
@@ -1080,10 +1086,9 @@ cnt_hit(struct sess *sp, struct worker *wrk, struct req *req)
 	VCL_hit_method(sp);
 
 	if (req->handling == VCL_RET_DELIVER) {
-		/* Dispose of any body part of the request */
-		(void)FetchReqBody(sp);
 		//AZ(wrk->busyobj->bereq->ws);
 		//AZ(wrk->busyobj->beresp->ws);
+		(void)FetchReqBody(sp, 0);
 		sp->step = STP_PREPRESP;
 		return (0);
 	}
@@ -1117,10 +1122,6 @@ cnt_hit(struct sess *sp, struct worker *wrk, struct req *req)
  * encounter a busy object.
  *
 DOT subgraph xcluster_lookup {
-DOT	hash [
-DOT		shape=record
-DOT		label="vcl_hash()|req."
-DOT	]
 DOT	lookup [
 DOT		shape=diamond
 DOT		label="obj in cache ?\ncreate if not"
@@ -1129,7 +1130,6 @@ DOT	lookup2 [
 DOT		shape=diamond
 DOT		label="obj.f.pass ?"
 DOT	]
-DOT	hash -> lookup [label="hash",style=bold,color=green]
 DOT	lookup -> lookup2 [label="yes",style=bold,color=green]
 DOT }
 DOT lookup2 -> hit [label="no", style=bold,color=green]
@@ -1343,7 +1343,7 @@ DOT err_pass [label="ERROR",shape=plaintext]
  */
 
 static int
-cnt_pass(struct sess *sp, struct worker *wrk, struct req *req)
+cnt_pass(struct sess *sp, struct worker *wrk, const struct req *req)
 {
 	CHECK_OBJ_NOTNULL(sp, SESS_MAGIC);
 	CHECK_OBJ_NOTNULL(wrk, WORKER_MAGIC);
@@ -1370,7 +1370,6 @@ cnt_pass(struct sess *sp, struct worker *wrk, struct req *req)
 	}
 	assert(req->handling == VCL_RET_PASS);
 	wrk->acct_tmp.pass++;
-	req->sendbody = 1;
 	sp->step = STP_FETCH;
 	return (0);
 }
@@ -1434,11 +1433,19 @@ cnt_pipe(struct sess *sp, struct worker *wrk, const struct req *req)
 /*--------------------------------------------------------------------
  * RECV
  * We have a complete request, set everything up and start it.
+ * We can come here both with a request from the client and with
+ * a interior request during ESI delivery.
  *
 DOT subgraph xcluster_recv {
 DOT	recv [
 DOT		shape=record
-DOT		label="vcl_recv()|req."
+DOT		label="{cnt_recv:|{vcl_recv\{\}|req.*}}"
+DOT	]
+DOT }
+DOT subgraph xcluster_hash {
+DOT	hash [
+DOT		shape=record
+DOT		label="{cnt_recv:|{vcl_hash\{\}|req.*}}"
 DOT	]
 DOT }
 DOT ESI_REQ [ shape=hexagon ]
@@ -1449,6 +1456,7 @@ DOT recv -> pass2 [label="pass",style=bold,color=red]
 DOT recv -> err_recv [label="error"]
 DOT err_recv [label="ERROR",shape=plaintext]
 DOT recv -> hash [label="lookup",style=bold,color=green]
+DOT hash -> lookup [label="hash",style=bold,color=green]
  */
 
 static int
@@ -1481,6 +1489,11 @@ cnt_recv(struct sess *sp, struct worker *wrk, struct req *req)
 	recv_handling = req->handling;
 
 	if (req->restarts >= cache_param->max_restarts) {
+		/*
+		 * XXX: Why not before vcl_recv{} ?  We go to vcl_error{}
+		 * XXX: without vcl_recv{} on 413 and 417 already.
+		 * XXX tell vcl_error why we come
+		 */
 		if (req->err_code == 0)
 			req->err_code = 503;
 		sp->step = STP_ERROR;
@@ -1499,7 +1512,7 @@ cnt_recv(struct sess *sp, struct worker *wrk, struct req *req)
 		}
 	}
 
-	req->sha256ctx = &sha256ctx;
+	req->sha256ctx = &sha256ctx;	/* so HSH_AddString() can find it */
 	SHA256_Init(req->sha256ctx);
 	VCL_hash_method(sp);
 	assert(req->handling == VCL_RET_HASH);
@@ -1511,10 +1524,8 @@ cnt_recv(struct sess *sp, struct worker *wrk, struct req *req)
 	else
 		req->wantbody = 1;
 
-	req->sendbody = 0;
 	switch(recv_handling) {
 	case VCL_RET_LOOKUP:
-		/* XXX: discard req body, if any */
 		sp->step = STP_LOOKUP;
 		return (0);
 	case VCL_RET_PIPE:
@@ -1530,7 +1541,6 @@ cnt_recv(struct sess *sp, struct worker *wrk, struct req *req)
 		sp->step = STP_PASS;
 		return (0);
 	case VCL_RET_ERROR:
-		/* XXX: discard req body, if any */
 		sp->step = STP_ERROR;
 		return (0);
 	default:
@@ -1563,10 +1573,10 @@ cnt_start(struct sess *sp, struct worker *wrk, struct req *req)
 	AZ(req->obj);
 	AZ(req->vcl);
 	AZ(req->esi_level);
+	assert(!isnan(sp->t_req));
 
 	/* Update stats of various sorts */
 	wrk->stats.client_req++;
-	assert(!isnan(sp->t_req));
 	wrk->acct_tmp.req++;
 
 	/* Assign XID and log */
@@ -1609,11 +1619,14 @@ cnt_start(struct sess *sp, struct worker *wrk, struct req *req)
 	}
 	http_Unset(req->http, H_Expect);
 
+	/* XXX: pull in req-body and make it available instead. */
+	req->reqbodydone = 0;
+
 	HTTP_Copy(req->http0, req->http);	/* Copy for restart/ESI use */
 
 	if (req->err_code)
 		sp->step = STP_ERROR;
-	else 
+	else
 		sp->step = STP_RECV;
 	return (0);
 }

bin/varnishd/cache/cache_fetch.c

@@ -329,14 +329,20 @@ fetch_eof(struct worker *wrk, struct http_conn *htc)
  */
 
 int
-FetchReqBody(const struct sess *sp)
+FetchReqBody(const struct sess *sp, int sendbody)
 {
 	unsigned long content_length;
 	char buf[8192];
 	char *ptr, *endp;
 	int rdcnt;
 
+	if (sp->req->reqbodydone) {
+		AZ(sendbody);
+		return (0);
+	}
+		
 	if (http_GetHdr(sp->req->http, H_Content_Length, &ptr)) {
+		sp->req->reqbodydone = 1;
 
 		content_length = strtoul(ptr, &endp, 10);
 		/* XXX should check result of conversion */
@@ -349,11 +355,12 @@ FetchReqBody(const struct sess *sp)
 			if (rdcnt <= 0)
 				return (1);
 			content_length -= rdcnt;
-			if (!sp->req->sendbody)
-				continue;
-			(void)WRW_Write(sp->wrk, buf, rdcnt); /* XXX: stats ? */
-			if (WRW_Flush(sp->wrk))
-				return (2);
+			if (sendbody) {
+				/* XXX: stats ? */
+				(void)WRW_Write(sp->wrk, buf, rdcnt);
+				if (WRW_Flush(sp->wrk))
+					return (2);
+			}
 		}
 	}
 	if (http_GetHdr(sp->req->http, H_Transfer_Encoding, NULL)) {
@@ -375,7 +382,7 @@ FetchReqBody(const struct sess *sp)
  */
 
 int
-FetchHdr(struct sess *sp, int need_host_hdr)
+FetchHdr(struct sess *sp, int need_host_hdr, int sendbody)
 {
 	struct vbc *vc;
 	struct worker *wrk;
@@ -422,7 +429,7 @@ FetchHdr(struct sess *sp, int need_host_hdr)
 	(void)http_Write(wrk, vc->vsl_id, hp, 0);	/* XXX: stats ? */
 
 	/* Deal with any message-body the request might have */
-	i = FetchReqBody(sp);
+	i = FetchReqBody(sp, sendbody);
 	if (WRW_FlushRelease(wrk) || i > 0) {
 		WSP(sp, SLT_FetchError, "backend write error: %d (%s)",
 		    errno, strerror(errno));