[master] 9a63616 Cleanup all the easy bits of the VSL api in varnishd.

Poul-Henning Kamp phk at varnish-cache.org
Sun Feb 19 09:42:05 CET 2012


commit 9a63616cb869286a0a3f8139f8f0f1205ad87e80
Author: Poul-Henning Kamp <phk at FreeBSD.org>
Date:   Sun Feb 19 08:40:55 2012 +0000

    Cleanup all the easy bits of the VSL api in varnishd.
    
    We now have:
    	VSL() -> send directly to global VSL buffer
    	VSLb() -> send to buffered VSL
    	VSLbt() -> send txt to buffered VSL

diff --git a/bin/varnishd/cache/cache.h b/bin/varnishd/cache/cache.h
index d441fca..2dd32bf 100644
--- a/bin/varnishd/cache/cache.h
+++ b/bin/varnishd/cache/cache.h
@@ -918,13 +918,13 @@ void VSM_Free(void *ptr);
 #ifdef VSL_ENDMARKER
 void VSL(enum VSL_tag_e tag, int id, const char *fmt, ...)
     __printflike(3, 4);
-void WSLR(struct vsl_log *, enum VSL_tag_e tag, int id, txt t);
 void WSL(struct vsl_log *, enum VSL_tag_e tag, int id, const char *fmt, ...)
     __printflike(4, 5);
-void VSLB(struct busyobj *, enum VSL_tag_e tag, const char *fmt, ...)
+void VSLb(struct vsl_log *, enum VSL_tag_e tag, const char *fmt, ...)
     __printflike(3, 4);
+void VSLbt(struct vsl_log *, enum VSL_tag_e tag, txt t);
 
-void WSL_Flush(struct vsl_log *, int overflow);
+void VSL_Flush(struct vsl_log *, int overflow);
 
 #define DSL(flag, tag, id, ...)					\
 	do {							\
@@ -932,9 +932,6 @@ void WSL_Flush(struct vsl_log *, int overflow);
 			VSL((tag), (id), __VA_ARGS__);		\
 	} while (0)
 
-#define WSP(sess, tag, ...)					\
-	WSL((sess)->wrk->vsl, tag, (sess)->vsl_id, __VA_ARGS__)
-
 #define INCOMPL() do {							\
 	VSL(SLT_Debug, 0, "INCOMPLETE AT: %s(%d)", __func__, __LINE__); \
 	fprintf(stderr,							\
diff --git a/bin/varnishd/cache/cache_backend.c b/bin/varnishd/cache/cache_backend.c
index 6e86538..085c7a7 100644
--- a/bin/varnishd/cache/cache_backend.c
+++ b/bin/varnishd/cache/cache_backend.c
@@ -183,7 +183,7 @@ bes_conn_try(const struct sess *sp, struct vbc *vc, const struct vdi_simple *vs)
 	} else {
 		vc->vsl_id = s | VSL_BACKENDMARKER;
 		VTCP_myname(s, abuf1, sizeof abuf1, pbuf1, sizeof pbuf1);
-		WSL(sp->wrk->vsl, SLT_BackendOpen, vc->vsl_id, "%s %s %s ",
+		WSL(sp->req->vsl, SLT_BackendOpen, vc->vsl_id, "%s %s %s ",
 		    vs->backend->display_name, abuf1, pbuf1);
 	}
 
@@ -346,7 +346,7 @@ vbe_GetVbe(const struct sess *sp, struct vdi_simple *vs)
 		if (vbe_CheckFd(vc->fd)) {
 			/* XXX locking of stats */
 			VSC_C_main->backend_reuse += 1;
-			WSP(sp, SLT_Backend, "%d %s %s",
+			VSLb(sp->req->vsl, SLT_Backend, "%d %s %s",
 			    vc->fd, sp->req->director->vcl_name,
 			    bp->display_name);
 			vc->vdis = vs;
@@ -359,7 +359,7 @@ vbe_GetVbe(const struct sess *sp, struct vdi_simple *vs)
 
 		/* Checkpoint log to flush all info related to this connection
 		   before the OS reuses the FD */
-		WSL_Flush(sp->wrk->vsl, 0);
+		VSL_Flush(sp->wrk->vsl, 0);
 
 		VTCP_close(&vc->fd);
 		VBE_DropRefConn(bp);
@@ -389,7 +389,7 @@ vbe_GetVbe(const struct sess *sp, struct vdi_simple *vs)
 	}
 	vc->backend = bp;
 	VSC_C_main->backend_conn++;
-	WSP(sp, SLT_Backend, "%d %s %s",
+	VSLb(sp->req->vsl, SLT_Backend, "%d %s %s",
 	    vc->fd, sp->req->director->vcl_name, bp->display_name);
 	vc->vdis = vs;
 	return (vc);
diff --git a/bin/varnishd/cache/cache_ban.c b/bin/varnishd/cache/cache_ban.c
index 24a150e..a9ff554 100644
--- a/bin/varnishd/cache/cache_ban.c
+++ b/bin/varnishd/cache/cache_ban.c
@@ -761,7 +761,8 @@ ban_check_object(struct object *o, const struct sess *sp, int has_req)
 		oc->ban = NULL;
 		oc_updatemeta(oc);
 		/* BAN also changed, but that is not important any more */
-		WSP(sp, SLT_ExpBan, "%u was banned", o->xid);
+		/* XXX: no req in lurker */
+		VSLb(sp->wrk->vsl, SLT_ExpBan, "%u was banned", o->xid);
 		EXP_Rearm(o);
 		return (1);
 	}
@@ -954,7 +955,7 @@ ban_lurker(struct sess *sp, void *priv)
 		}
 
 		i = ban_lurker_work(sp, pass);
-		WSL_Flush(sp->wrk->vsl, 0);
+		VSL_Flush(sp->wrk->vsl, 0);
 		WRK_SumStat(sp->wrk);
 		if (i) {
 			pass += (1 << LURK_SHIFT);
diff --git a/bin/varnishd/cache/cache_busyobj.c b/bin/varnishd/cache/cache_busyobj.c
index 8f0f31e..32ae7c8 100644
--- a/bin/varnishd/cache/cache_busyobj.c
+++ b/bin/varnishd/cache/cache_busyobj.c
@@ -183,7 +183,7 @@ VBO_DerefBusyObj(struct worker *wrk, struct busyobj **pbo)
 	if (r)
 		return;
 
-	WSL_Flush(vbo->bo.vsl, 0);
+	VSL_Flush(vbo->bo.vsl, 0);
 	/* XXX: Sanity checks & cleanup */
 	memset(&vbo->bo, 0, sizeof vbo->bo);
 
diff --git a/bin/varnishd/cache/cache_center.c b/bin/varnishd/cache/cache_center.c
index 4b0429a..9619a6e 100644
--- a/bin/varnishd/cache/cache_center.c
+++ b/bin/varnishd/cache/cache_center.c
@@ -394,14 +394,14 @@ cnt_done(struct sess *sp, struct worker *wrk, struct req *req)
 		/* XXX: Add StatReq == StatSess */
 		/* XXX: Workaround for pipe */
 		if (sp->fd >= 0) {
-			WSP(sp, SLT_Length, "%ju",
+			VSLb(sp->req->vsl, SLT_Length, "%ju",
 			    (uintmax_t)req->req_bodybytes);
 		}
-		WSP(sp, SLT_ReqEnd, "%u %.9f %.9f %.9f %.9f %.9f",
+		VSLb(sp->req->vsl, SLT_ReqEnd, "%u %.9f %.9f %.9f %.9f %.9f",
 		    req->xid, sp->t_req, sp->t_idle, dh, dp, da);
 	}
 	req->xid = 0;
-	WSL_Flush(wrk->vsl, 0);
+	VSL_Flush(wrk->vsl, 0);
 
 	sp->t_req = NAN;
 	req->t_resp = NAN;
@@ -941,10 +941,12 @@ cnt_first(struct sess *sp, struct worker *wrk)
 		    &sp->mysockaddrlen));
 		VTCP_name(&sp->mysockaddr, sp->mysockaddrlen,
 		    laddr, sizeof laddr, lport, sizeof lport);
-		WSP(sp, SLT_SessionOpen, "%s %s %s %s",
+		/* XXX: have no req yet */
+		VSLb(sp->wrk->vsl, SLT_SessionOpen, "%s %s %s %s",
 		    sp->addr, sp->port, laddr, lport);
 	} else {
-		WSP(sp, SLT_SessionOpen, "%s %s %s",
+		/* XXX: have no req yet */
+		VSLb(sp->wrk->vsl, SLT_SessionOpen, "%s %s %s",
 		    sp->addr, sp->port, sp->mylsock->name);
 	}
 
@@ -1116,7 +1118,7 @@ cnt_lookup(struct sess *sp, struct worker *wrk, struct req *req)
 
 	if (oc->flags & OC_F_PASS) {
 		wrk->stats.cache_hitpass++;
-		WSP(sp, SLT_HitPass, "%u", req->obj->xid);
+		VSLb(sp->req->vsl, SLT_HitPass, "%u", req->obj->xid);
 		(void)HSH_Deref(&wrk->stats, NULL, &req->obj);
 		AZ(req->objcore);
 		sp->step = STP_PASS;
@@ -1124,7 +1126,7 @@ cnt_lookup(struct sess *sp, struct worker *wrk, struct req *req)
 	}
 
 	wrk->stats.cache_hit++;
-	WSP(sp, SLT_Hit, "%u", req->obj->xid);
+	VSLb(sp->req->vsl, SLT_Hit, "%u", req->obj->xid);
 	sp->step = STP_HIT;
 	return (0);
 }
@@ -1450,7 +1452,8 @@ cnt_start(struct sess *sp, struct worker *wrk, struct req *req)
 
 	/* Assign XID and log */
 	req->xid = ++xids;				/* XXX not locked */
-	WSP(sp, SLT_ReqStart, "%s %s %u", sp->addr, sp->port,  req->xid);
+	VSLb(sp->req->vsl, SLT_ReqStart, "%s %s %u",
+	    sp->addr, sp->port,  req->xid);
 
 	/* Borrow VCL reference from worker thread */
 	VCL_Refresh(&wrk->vcl);
@@ -1521,10 +1524,11 @@ cnt_diag(struct sess *sp, const char *state)
 		obj = sp->req->obj;
 	}
 
-	if (sp->wrk != NULL) {
-		WSP(sp, SLT_Debug, "vsl_id %u STP_%s sp %p obj %p vcl %p",
+	if (sp->req != NULL) {
+		VSLb(sp->req->vsl,  SLT_Debug,
+		    "vsl_id %u STP_%s sp %p obj %p vcl %p",
 		    sp->vsl_id, state, sp, obj, vcl);
-		WSL_Flush(sp->wrk->vsl, 0);
+		VSL_Flush(sp->req->vsl, 0);
 	} else {
 		VSL(SLT_Debug, sp->vsl_id,
 		    "vsl_id %u STP_%s sp %p obj %p vcl %p",
@@ -1605,7 +1609,7 @@ CNT_Session(struct sess *sp)
 		WS_Assert(wrk->aws);
 		CHECK_OBJ_ORNULL(wrk->nobjhead, OBJHEAD_MAGIC);
 	}
-	WSL_Flush(wrk->vsl, 0);
+	VSL_Flush(wrk->vsl, 0);
 #define ACCT(foo)	AZ(wrk->acct_tmp.foo);
 #include "tbl/acct_fields.h"
 #undef ACCT
diff --git a/bin/varnishd/cache/cache_dir.c b/bin/varnishd/cache/cache_dir.c
index b1359e3..ab74b59 100644
--- a/bin/varnishd/cache/cache_dir.c
+++ b/bin/varnishd/cache/cache_dir.c
@@ -59,8 +59,8 @@ VDI_CloseFd(struct worker *wrk, struct vbc **vbp)
 
 	/* Checkpoint log to flush all info related to this connection
 	   before the OS reuses the FD */
-	WSL_Flush(wrk->vsl, 0);
-	WSL_Flush(vc->vsl, 0);
+	VSL_Flush(wrk->vsl, 0);
+	VSL_Flush(vc->vsl, 0);
 	vc->vsl->wid = vc->orig_vsl_id;
 	vc->vsl = NULL;
 	vc->orig_vsl_id = 0;
@@ -95,8 +95,8 @@ VDI_RecycleFd(struct worker *wrk, struct vbc **vbp)
 	 * Flush the shmlog, so that another session reusing this backend
 	 * will log chronologically later than our use of it.
 	 */
-	WSL_Flush(wrk->vsl, 0);
-	WSL_Flush(vc->vsl, 0);
+	VSL_Flush(wrk->vsl, 0);
+	VSL_Flush(vc->vsl, 0);
 	vc->vsl->wid = vc->orig_vsl_id;
 	vc->vsl = NULL;
 	vc->orig_vsl_id = 0;
diff --git a/bin/varnishd/cache/cache_esi_deliver.c b/bin/varnishd/cache/cache_esi_deliver.c
index 54302c8..2c4d3d0 100644
--- a/bin/varnishd/cache/cache_esi_deliver.c
+++ b/bin/varnishd/cache/cache_esi_deliver.c
@@ -98,7 +98,7 @@ ved_include(struct sess *sp, const char *src, const char *host)
 		if (sp->step == STP_DONE)
 			break;
 		AZ(sp->wrk);
-		WSL_Flush(w->vsl, 0);
+		VSL_Flush(w->vsl, 0);
 		DSL(0x20, SLT_Debug, sp->vsl_id, "loop waiting for ESI");
 		(void)usleep(10000);
 	}
diff --git a/bin/varnishd/cache/cache_esi_parse.c b/bin/varnishd/cache/cache_esi_parse.c
index 053f614..6eac8d3 100644
--- a/bin/varnishd/cache/cache_esi_parse.c
+++ b/bin/varnishd/cache/cache_esi_parse.c
@@ -186,7 +186,7 @@ vep_error(const struct vep_state *vep, const char *p)
 
 	VSC_C_main->esi_errors++;
 	l = (intmax_t)(vep->ver_p - vep->hack_p);
-	VSLB(vep->bo, SLT_ESI_xmlerror, "ERR at %jd %s", l, p);
+	VSLb(vep->bo->vsl, SLT_ESI_xmlerror, "ERR at %jd %s", l, p);
 
 }
 
@@ -202,7 +202,7 @@ vep_warn(const struct vep_state *vep, const char *p)
 	VSC_C_main->esi_warnings++;
 	l = (intmax_t)(vep->ver_p - vep->hack_p);
 	printf("WARNING at %jd %s\n", l, p);
-	VSLB(vep->bo, SLT_ESI_xmlerror, "WARN at %jd %s", l, p);
+	VSLb(vep->bo->vsl, SLT_ESI_xmlerror, "WARN at %jd %s", l, p);
 
 }
 
@@ -601,7 +601,7 @@ VEP_Parse(const struct busyobj *bo, const char *p, size_t l)
 				p++;
 				vep->state = VEP_STARTTAG;
 			} else if (p < e) {
-				VSLB(vep->bo, SLT_ESI_xmlerror,
+				VSLb(vep->bo->vsl, SLT_ESI_xmlerror,
 				    "No ESI processing, first char not '<'");
 				vep->state = VEP_NOTXML;
 			}
diff --git a/bin/varnishd/cache/cache_expire.c b/bin/varnishd/cache/cache_expire.c
index 060ed58..e0f3d27 100644
--- a/bin/varnishd/cache/cache_expire.c
+++ b/bin/varnishd/cache/cache_expire.c
@@ -342,7 +342,7 @@ exp_timer(struct sess *sp, void *priv)
 	oc = NULL;
 	while (1) {
 		if (oc == NULL) {
-			WSL_Flush(sp->wrk->vsl, 0);
+			VSL_Flush(sp->wrk->vsl, 0);
 			WRK_SumStat(sp->wrk);
 			VTIM_sleep(cache_param->expiry_sleep);
 			t = VTIM_real();
@@ -445,7 +445,7 @@ EXP_NukeOne(struct busyobj *bo, struct lru *lru)
 		return (-1);
 
 	/* XXX: bad idea for -spersistent */
-	WSL(bo->vsl, SLT_ExpKill, -1, "%u LRU", oc_getxid(bo->stats, oc));
+	VSLb(bo->vsl, SLT_ExpKill, "%u LRU", oc_getxid(bo->stats, oc));
 	(void)HSH_Deref(bo->stats, oc, NULL);
 	return (1);
 }
diff --git a/bin/varnishd/cache/cache_fetch.c b/bin/varnishd/cache/cache_fetch.c
index a8b3dcb..48db272 100644
--- a/bin/varnishd/cache/cache_fetch.c
+++ b/bin/varnishd/cache/cache_fetch.c
@@ -58,9 +58,9 @@ FetchError2(struct busyobj *bo, const char *error, const char *more)
 	CHECK_OBJ_NOTNULL(bo, BUSYOBJ_MAGIC);
 	if (!bo->fetch_failed) {
 		if (more == NULL)
-			VSLB(bo, SLT_FetchError, "%s", error);
+			VSLb(bo->vsl, SLT_FetchError, "%s", error);
 		else
-			VSLB(bo, SLT_FetchError, "%s: %s", error, more);
+			VSLb(bo->vsl, SLT_FetchError, "%s: %s", error, more);
 	}
 	bo->fetch_failed = 1;
 	return (-1);
@@ -364,7 +364,7 @@ FetchReqBody(const struct sess *sp, int sendbody)
 	}
 	if (http_GetHdr(sp->req->http, H_Transfer_Encoding, NULL)) {
 		/* XXX: Handle chunked encoding. */
-		WSP(sp, SLT_Debug, "Transfer-Encoding in request");
+		VSLb(sp->req->vsl, SLT_Debug, "Transfer-Encoding in request");
 		return (1);
 	}
 	return (0);
@@ -408,7 +408,7 @@ FetchHdr(struct sess *sp, int need_host_hdr, int sendbody)
 
 	wrk->busyobj->vbc = VDI_GetFd(NULL, sp);
 	if (wrk->busyobj->vbc == NULL) {
-		WSP(sp, SLT_FetchError, "no backend connection");
+		VSLb(sp->req->vsl, SLT_FetchError, "no backend connection");
 		return (-1);
 	}
 	vc = wrk->busyobj->vbc;
@@ -430,7 +430,8 @@ FetchHdr(struct sess *sp, int need_host_hdr, int sendbody)
 	/* Deal with any message-body the request might have */
 	i = FetchReqBody(sp, sendbody);
 	if (WRW_FlushRelease(wrk) || i > 0) {
-		WSP(sp, SLT_FetchError, "backend write error: %d (%s)",
+		VSLb(sp->req->vsl, SLT_FetchError,
+		    "backend write error: %d (%s)",
 		    errno, strerror(errno));
 		VDI_CloseFd(wrk, &wrk->busyobj->vbc);
 		/* XXX: other cleanup ? */
@@ -438,7 +439,7 @@ FetchHdr(struct sess *sp, int need_host_hdr, int sendbody)
 	}
 
 	/* Checkpoint the vsl.here */
-	WSL_Flush(wrk->vsl, 0);
+	VSL_Flush(wrk->vsl, 0);
 
 	/* XXX is this the right place? */
 	VSC_C_main->backend_req++;
@@ -454,7 +455,8 @@ FetchHdr(struct sess *sp, int need_host_hdr, int sendbody)
 	i = HTC_Rx(htc);
 
 	if (i < 0) {
-		WSP(sp, SLT_FetchError, "http first read error: %d %d (%s)",
+		VSLb(sp->req->vsl, SLT_FetchError,
+		    "http first read error: %d %d (%s)",
 		    i, errno, strerror(errno));
 		VDI_CloseFd(wrk, &wrk->busyobj->vbc);
 		/* XXX: other cleanup ? */
@@ -467,7 +469,7 @@ FetchHdr(struct sess *sp, int need_host_hdr, int sendbody)
 	while (i == 0) {
 		i = HTC_Rx(htc);
 		if (i < 0) {
-			WSP(sp, SLT_FetchError,
+			VSLb(sp->req->vsl, SLT_FetchError,
 			    "http first read error: %d %d (%s)",
 			    i, errno, strerror(errno));
 			VDI_CloseFd(wrk, &wrk->busyobj->vbc);
@@ -479,7 +481,7 @@ FetchHdr(struct sess *sp, int need_host_hdr, int sendbody)
 	hp = wrk->busyobj->beresp;
 
 	if (http_DissectResponse(hp, htc)) {
-		WSP(sp, SLT_FetchError, "http format error");
+		VSLb(sp->req->vsl, SLT_FetchError, "http format error");
 		VDI_CloseFd(wrk, &wrk->busyobj->vbc);
 		/* XXX: other cleanup ? */
 		return (-1);
@@ -579,7 +581,7 @@ FetchBody(struct worker *wrk, struct object *obj)
 
 	bo->fetch_obj = NULL;
 
-	VSLB(bo, SLT_Fetch_Body, "%u(%s) cls %d mklen %d",
+	VSLb(bo->vsl, SLT_Fetch_Body, "%u(%s) cls %d mklen %d",
 	    bo->body_status, body_status(bo->body_status),
 	    cls, mklen);
 
@@ -601,7 +603,7 @@ FetchBody(struct worker *wrk, struct object *obj)
 	if (cls == 0 && bo->should_close)
 		cls = 1;
 
-	VSLB(bo, SLT_Length, "%zd", obj->len);
+	VSLb(bo->vsl, SLT_Length, "%zd", obj->len);
 
 	{
 	/* Sanity check fetch methods accounting */
diff --git a/bin/varnishd/cache/cache_gzip.c b/bin/varnishd/cache/cache_gzip.c
index 530d43b..d4511bc 100644
--- a/bin/varnishd/cache/cache_gzip.c
+++ b/bin/varnishd/cache/cache_gzip.c
@@ -395,7 +395,7 @@ VGZ_Destroy(struct vgz **vgp)
 	CHECK_OBJ_NOTNULL(vg, VGZ_MAGIC);
 	*vgp = NULL;
 
-	WSL(vg->vsl, SLT_Gzip, -1, "%s %jd %jd %jd %jd %jd",
+	VSLb(vg->vsl, SLT_Gzip, "%s %jd %jd %jd %jd %jd",
 	    vg->id,
 	    (intmax_t)vg->vz.total_in,
 	    (intmax_t)vg->vz.total_out,
diff --git a/bin/varnishd/cache/cache_hash.c b/bin/varnishd/cache/cache_hash.c
index 7188ff4..3d44cc4 100644
--- a/bin/varnishd/cache/cache_hash.c
+++ b/bin/varnishd/cache/cache_hash.c
@@ -163,7 +163,7 @@ HSH_AddString(const struct sess *sp, const char *str)
 	SHA256_Update(sp->req->sha256ctx, "#", 1);
 
 	if (cache_param->log_hash)
-		WSP(sp, SLT_Hash, "%s", str);
+		VSLb(sp->req->vsl, SLT_Hash, "%s", str);
 }
 
 /*---------------------------------------------------------------------
@@ -431,7 +431,7 @@ HSH_Lookup(struct sess *sp, struct objhead **poh)
 			VTAILQ_INSERT_TAIL(&oh->waitinglist->list, sp, list);
 		}
 		if (cache_param->diag_bitmap & 0x20)
-			WSP(sp, SLT_Debug,
+			VSLb(sp->req->vsl, SLT_Debug,
 				"on waiting list <%p>", oh);
 		SES_Charge(sp);
 		/*
diff --git a/bin/varnishd/cache/cache_http.c b/bin/varnishd/cache/cache_http.c
index 71533ef..f721ea2 100644
--- a/bin/varnishd/cache/cache_http.c
+++ b/bin/varnishd/cache/cache_http.c
@@ -78,7 +78,7 @@ http_VSLH(const struct http *hp, unsigned hdr)
 
 	AN(hp->vsl);
 	AN(hp->vsl->wid & (VSL_CLIENTMARKER|VSL_BACKENDMARKER));
-	WSLR(hp->vsl, http2shmlog(hp, hdr), -1, hp->hd[hdr]);
+	VSLbt(hp->vsl, http2shmlog(hp, hdr), hp->hd[hdr]);
 }
 
 /*--------------------------------------------------------------------*/
@@ -528,7 +528,7 @@ http_dissect_hdrs(struct http *hp, char *p, const struct http_conn *htc)
 
 		if (q - p > htc->maxhdr) {
 			VSC_C_main->losthdr++;
-			WSL(hp->vsl, SLT_LostHeader, -1, "%.*s",
+			VSLb(hp->vsl, SLT_LostHeader, "%.*s",
 			    (int)(q - p > 20 ? 20 : q - p), p);
 			return (413);
 		}
@@ -554,7 +554,7 @@ http_dissect_hdrs(struct http *hp, char *p, const struct http_conn *htc)
 			hp->nhd++;
 		} else {
 			VSC_C_main->losthdr++;
-			WSL(hp->vsl, SLT_LostHeader, -1, "%.*s",
+			VSLb(hp->vsl, SLT_LostHeader, "%.*s",
 			    (int)(q - p > 20 ? 20 : q - p), p);
 			return (413);
 		}
@@ -677,7 +677,7 @@ http_DissectRequest(const struct sess *sp)
 	retval = http_splitline(hp, htc,
 	    HTTP_HDR_REQ, HTTP_HDR_URL, HTTP_HDR_PROTO);
 	if (retval != 0) {
-		WSLR(sp->req->vsl, SLT_HttpGarbage, -1, htc->rxbuf);
+		VSLbt(sp->req->vsl, SLT_HttpGarbage, htc->rxbuf);
 		return (retval);
 	}
 	http_ProtoVer(hp);
@@ -724,7 +724,7 @@ http_DissectResponse(struct http *hp, const struct http_conn *htc)
 	}
 
 	if (retval != 0) {
-		WSLR(hp->vsl, SLT_HttpGarbage, -1, htc->rxbuf);
+		VSLbt(hp->vsl, SLT_HttpGarbage, htc->rxbuf);
 		assert(retval >= 100 && retval <= 999);
 		hp->status = retval;
 	} else {
@@ -842,7 +842,7 @@ http_filterfields(struct http *to, const struct http *fm, unsigned how)
 			to->nhd++;
 		} else  {
 			VSC_C_main->losthdr++;
-			WSLR(to->vsl, SLT_LostHeader, -1, fm->hd[u]);
+			VSLbt(to->vsl, SLT_LostHeader, fm->hd[u]);
 		}
 	}
 }
@@ -910,7 +910,7 @@ http_CopyHome(const struct http *hp)
 		} else {
 			/* XXX This leaves a slot empty */
 			VSC_C_main->losthdr++;
-			WSLR(hp->vsl, SLT_LostHeader, -1, hp->hd[u]);
+			VSLbt(hp->vsl, SLT_LostHeader, hp->hd[u]);
 			hp->hd[u].b = NULL;
 			hp->hd[u].e = NULL;
 		}
@@ -940,7 +940,7 @@ http_SetHeader(struct http *to, const char *hdr)
 	CHECK_OBJ_NOTNULL(to, HTTP_MAGIC);
 	if (to->nhd >= to->shd) {
 		VSC_C_main->losthdr++;
-		WSL(to->vsl, SLT_LostHeader, -1, "%s", hdr);
+		VSLb(to->vsl, SLT_LostHeader, "%s", hdr);
 		return;
 	}
 	http_SetH(to, to->nhd++, hdr);
@@ -958,7 +958,7 @@ http_PutField(const struct http *to, int field, const char *string)
 	l = strlen(string);
 	p = WS_Alloc(to->ws, l + 1);
 	if (p == NULL) {
-		WSL(to->vsl, SLT_LostHeader, -1, "%s", string);
+		VSLb(to->vsl, SLT_LostHeader, "%s", string);
 		to->hd[field].b = NULL;
 		to->hd[field].e = NULL;
 		to->hdf[field] = 0;
@@ -1011,7 +1011,7 @@ http_PrintfHeader(struct http *to, const char *fmt, ...)
 	va_end(ap);
 	if (n + 1 >= l || to->nhd >= to->shd) {
 		VSC_C_main->losthdr++;
-		WSL(to->vsl, SLT_LostHeader, -1, "%s", to->ws->f);
+		VSLb(to->vsl, SLT_LostHeader, "%s", to->ws->f);
 		WS_Release(to->ws, 0);
 	} else {
 		to->hd[to->nhd].b = to->ws->f;
diff --git a/bin/varnishd/cache/cache_httpconn.c b/bin/varnishd/cache/cache_httpconn.c
index d0b7199..890dfd3 100644
--- a/bin/varnishd/cache/cache_httpconn.c
+++ b/bin/varnishd/cache/cache_httpconn.c
@@ -224,7 +224,7 @@ HTC_Read(struct http_conn *htc, void *d, size_t len)
 		return (l);
 	i = read(htc->fd, p, len);
 	if (i < 0) {
-		WSL(htc->vsl, SLT_FetchError, -1, "%s", strerror(errno));
+		VSLb(htc->vsl, SLT_FetchError, "%s", strerror(errno));
 		return (i);
 	}
 	return (i + l);
diff --git a/bin/varnishd/cache/cache_rfc2616.c b/bin/varnishd/cache/cache_rfc2616.c
index 1b67d81..2c3a368 100644
--- a/bin/varnishd/cache/cache_rfc2616.c
+++ b/bin/varnishd/cache/cache_rfc2616.c
@@ -167,7 +167,7 @@ RFC2616_Ttl(const struct sess *sp)
 	}
 
 	/* calculated TTL, Our time, Date, Expires, max-age, age */
-	WSP(sp, SLT_TTL,
+	VSLb(sp->req->vsl, SLT_TTL,	/* XXX Bo->vsl ? */
 	    "%u RFC %.0f %.0f %.0f %.0f %.0f %.0f %.0f %u",
 	    sp->req->xid, expp->ttl, -1., -1., expp->entered,
 	    expp->age, h_date, h_expires, max_age);
diff --git a/bin/varnishd/cache/cache_session.c b/bin/varnishd/cache/cache_session.c
index 1bd74fe..15efc5f 100644
--- a/bin/varnishd/cache/cache_session.c
+++ b/bin/varnishd/cache/cache_session.c
@@ -375,7 +375,7 @@ SES_ReleaseReq(struct sess *sp)
 	AN(pp->pool);
 	CHECK_OBJ_NOTNULL(sp->req, REQ_MAGIC);
 	MPL_AssertSane(sp->req);
-	WSL_Flush(sp->req->vsl, 0);
+	VSL_Flush(sp->req->vsl, 0);
 	MPL_Free(pp->mpl_req, sp->req);
 	sp->req = NULL;
 }
diff --git a/bin/varnishd/cache/cache_shmlog.c b/bin/varnishd/cache/cache_shmlog.c
index d4dae9d..6a54101 100644
--- a/bin/varnishd/cache/cache_shmlog.c
+++ b/bin/varnishd/cache/cache_shmlog.c
@@ -133,7 +133,7 @@ vsl_get(unsigned len, unsigned records, unsigned flushes)
  */
 
 static void
-VSLR(enum VSL_tag_e tag, int id, const char *b, unsigned len)
+vslr(enum VSL_tag_e tag, int id, const char *b, unsigned len)
 {
 	uint32_t *p;
 	unsigned mlen;
@@ -161,18 +161,18 @@ VSL(enum VSL_tag_e tag, int id, const char *fmt, ...)
 
 	/*
 	 * XXX: consider formatting into a stack buffer then move into
-	 * XXX: shmlog with VSLR().
+	 * XXX: shmlog with vslr().
 	 */
 	AN(fmt);
 	va_start(ap, fmt);
 
 	if (strchr(fmt, '%') == NULL) {
-		VSLR(tag, id, fmt, strlen(fmt));
+		vslr(tag, id, fmt, strlen(fmt));
 	} else {
 		n = vsnprintf(buf, mlen, fmt, ap);
 		if (n > mlen)
 			n = mlen;
-		VSLR(tag, id, buf, n);
+		vslr(tag, id, buf, n);
 	}
 	va_end(ap);
 }
@@ -180,7 +180,7 @@ VSL(enum VSL_tag_e tag, int id, const char *fmt, ...)
 /*--------------------------------------------------------------------*/
 
 void
-WSL_Flush(struct vsl_log *vsl, int overflow)
+VSL_Flush(struct vsl_log *vsl, int overflow)
 {
 	uint32_t *p;
 	unsigned l;
@@ -202,8 +202,8 @@ WSL_Flush(struct vsl_log *vsl, int overflow)
 
 /*--------------------------------------------------------------------*/
 
-void
-WSLR(struct vsl_log *vsl, enum VSL_tag_e tag, int id, txt t)
+static void
+wslr(struct vsl_log *vsl, enum VSL_tag_e tag, int id, txt t)
 {
 	unsigned l, mlen;
 
@@ -223,7 +223,7 @@ WSLR(struct vsl_log *vsl, enum VSL_tag_e tag, int id, txt t)
 
 	/* Wrap if necessary */
 	if (VSL_END(vsl->wlp, l) >= vsl->wle)
-		WSL_Flush(vsl, 1);
+		VSL_Flush(vsl, 1);
 	assert (VSL_END(vsl->wlp, l) < vsl->wle);
 	memcpy(VSL_DATA(vsl->wlp), t.b, l);
 	vsl_hdr(tag, vsl->wlp, l, id);
@@ -231,7 +231,7 @@ WSLR(struct vsl_log *vsl, enum VSL_tag_e tag, int id, txt t)
 	assert(vsl->wlp < vsl->wle);
 	vsl->wlr++;
 	if (cache_param->diag_bitmap & 0x10000)
-		WSL_Flush(vsl, 0);
+		VSL_Flush(vsl, 0);
 }
 
 /*--------------------------------------------------------------------*/
@@ -253,13 +253,13 @@ wsl(struct vsl_log *vsl, enum VSL_tag_e tag, int id, const char *fmt, va_list ap
 	if (strchr(fmt, '%') == NULL) {
 		t.b = TRUST_ME(fmt);
 		t.e = strchr(t.b, '\0');
-		WSLR(vsl, tag, id, t);
+		wslr(vsl, tag, id, t);
 	} else {
 		assert(vsl->wlp < vsl->wle);
 
 		/* Wrap if we cannot fit a full size record */
 		if (VSL_END(vsl->wlp, mlen) >= vsl->wle)
-			WSL_Flush(vsl, 1);
+			VSL_Flush(vsl, 1);
 
 		p = VSL_DATA(vsl->wlp);
 		n = vsnprintf(p, mlen, fmt, ap);
@@ -271,7 +271,7 @@ wsl(struct vsl_log *vsl, enum VSL_tag_e tag, int id, const char *fmt, va_list ap
 		vsl->wlr++;
 	}
 	if (cache_param->diag_bitmap & 0x10000)
-		WSL_Flush(vsl, 0);
+		VSL_Flush(vsl, 0);
 }
 
 /*--------------------------------------------------------------------*/
@@ -290,20 +290,31 @@ WSL(struct vsl_log *vsl, enum VSL_tag_e tag, int id, const char *fmt, ...)
 }
 
 
-/*--------------------------------------------------------------------*/
+/*--------------------------------------------------------------------
+ * VSL-buffered
+ */
 
 void
-VSLB(struct busyobj *bo, enum VSL_tag_e tag, const char *fmt, ...)
+VSLb(struct vsl_log *vsl, enum VSL_tag_e tag, const char *fmt, ...)
 {
 	va_list ap;
 
-	CHECK_OBJ_NOTNULL(bo, BUSYOBJ_MAGIC);
 	AN(fmt);
 	va_start(ap, fmt);
-	wsl(bo->vsl, tag, bo->vsl->wid, fmt, ap);
+	wsl(vsl, tag, vsl->wid, fmt, ap);
 	va_end(ap);
 }
 
+/*--------------------------------------------------------------------
+ * VSL-buffered-txt
+ */
+
+void
+VSLbt(struct vsl_log *vsl, enum VSL_tag_e tag, txt t)
+{
+	wslr(vsl, tag, -1, t);
+}
+
 /*--------------------------------------------------------------------*/
 
 void
diff --git a/bin/varnishd/cache/cache_vary.c b/bin/varnishd/cache/cache_vary.c
index 9ad41d0..7ba9c60 100644
--- a/bin/varnishd/cache/cache_vary.c
+++ b/bin/varnishd/cache/cache_vary.c
@@ -79,7 +79,8 @@ VRY_Create(const struct sess *sp, const struct http *hp)
 	AN(sbh);
 
 	if (*v == ':') {
-		WSP(sp, SLT_Error, "Vary header had extra ':', fix backend");
+		VSLb(sp->req->vsl, SLT_Error,
+		    "Vary header had extra ':', fix backend");
 		v++;
 	}
 	for (p = v; *p; p++) {
diff --git a/bin/varnishd/cache/cache_vcl.c b/bin/varnishd/cache/cache_vcl.c
index ad5acf0..b68627b 100644
--- a/bin/varnishd/cache/cache_vcl.c
+++ b/bin/varnishd/cache/cache_vcl.c
@@ -335,9 +335,10 @@ VCL_##func##_method(struct sess *sp)					\
 									\
 	sp->req->handling = 0;						\
 	sp->req->cur_method = VCL_MET_ ## upper;			\
-	WSP(sp, SLT_VCL_call, "%s", #func);				\
+	VSLb(sp->req->vsl, SLT_VCL_call, "%s", #func);			\
 	(void)sp->req->vcl->func##_func(sp);				\
-	WSP(sp, SLT_VCL_return, "%s", VCL_Return_Name(sp->req->handling)); \
+	VSLb(sp->req->vsl, SLT_VCL_return, "%s",			\
+	    VCL_Return_Name(sp->req->handling));			\
 	sp->req->cur_method = 0;					\
 	assert((1U << sp->req->handling) & bitmap);			\
 	assert(!((1U << sp->req->handling) & ~bitmap));			\
diff --git a/bin/varnishd/cache/cache_vrt.c b/bin/varnishd/cache/cache_vrt.c
index 6271e49..c9135dc 100644
--- a/bin/varnishd/cache/cache_vrt.c
+++ b/bin/varnishd/cache/cache_vrt.c
@@ -56,7 +56,7 @@ VRT_error(const struct sess *sp, unsigned code, const char *reason)
 {
 
 	CHECK_OBJ_NOTNULL(sp, SESS_MAGIC);
-	WSL(sp->wrk->vsl, SLT_Debug, 0, "VCL_error(%u, %s)", code, reason ?
+	VSLb(sp->req->vsl, SLT_Debug, "VCL_error(%u, %s)", code, reason ?
 	    reason : "(null)");
 	if (code < 100 || code > 999)
 		code = 503;
@@ -75,7 +75,7 @@ VRT_count(const struct sess *sp, unsigned u)
 		return;
 	CHECK_OBJ_NOTNULL(sp, SESS_MAGIC);
 	if (cache_param->vcl_trace)
-		WSP(sp, SLT_VCL_trace, "%u %u.%u", u,
+		VSLb(sp->req->vsl, SLT_VCL_trace, "%u %u.%u", u,
 		    sp->req->vcl->ref[u].line, sp->req->vcl->ref[u].pos);
 }
 
@@ -85,7 +85,7 @@ void
 VRT_acl_log(const struct sess *sp, const char *msg)
 {
 
-	WSP(sp, SLT_VCL_acl, "%s", msg);
+	VSLb(sp->req->vsl, SLT_VCL_acl, "%s", msg);
 }
 
 /*--------------------------------------------------------------------*/
@@ -228,7 +228,7 @@ VRT_SetHdr(const struct sess *sp , enum gethdr_e where, const char *hdr,
 	} else {
 		b = VRT_String(hp->ws, hdr + 1, p, ap);
 		if (b == NULL) {
-			WSP(sp, SLT_LostHeader, "%s", hdr + 1);
+			VSLb(sp->req->vsl, SLT_LostHeader, "%s", hdr + 1);
 		} else {
 			http_Unset(hp, hdr);
 			http_SetHeader(hp, b);
diff --git a/bin/varnishd/cache/cache_vrt_re.c b/bin/varnishd/cache/cache_vrt_re.c
index 867ec86..765cd27 100644
--- a/bin/varnishd/cache/cache_vrt_re.c
+++ b/bin/varnishd/cache/cache_vrt_re.c
@@ -75,7 +75,8 @@ VRT_re_match(const struct sess *sp, const char *s, void *re)
 	if (i >= 0)
 		return (1);
 	if (i < VRE_ERROR_NOMATCH )
-		WSP(sp, SLT_VCL_Error, "Regexp matching returned %d", i);
+		VSLb(sp->req->vsl, SLT_VCL_Error,
+		    "Regexp matching returned %d", i);
 	return (0);
 }
 
@@ -108,7 +109,8 @@ VRT_regsub(const struct sess *sp, int all, const char *str, void *re,
 	if (i == VRE_ERROR_NOMATCH)
 		return(str);
 	if (i < VRE_ERROR_NOMATCH ) {
-		WSP(sp, SLT_VCL_Error, "Regexp matching returned %d", i);
+		VSLb(sp->req->vsl, SLT_VCL_Error,
+		    "Regexp matching returned %d", i);
 		return(str);
 	}
 
@@ -146,7 +148,7 @@ VRT_regsub(const struct sess *sp, int all, const char *str, void *re,
 		    &cache_param->vre_limits);
 		if (i < VRE_ERROR_NOMATCH ) {
 			WS_Release(sp->req->http->ws, 0);
-			WSP(sp, SLT_VCL_Error,
+			VSLb(sp->req->vsl, SLT_VCL_Error,
 			    "Regexp matching returned %d", i);
 			return(str);
 		}
diff --git a/bin/varnishd/cache/cache_vrt_var.c b/bin/varnishd/cache/cache_vrt_var.c
index 417fcee..50f4411 100644
--- a/bin/varnishd/cache/cache_vrt_var.c
+++ b/bin/varnishd/cache/cache_vrt_var.c
@@ -46,16 +46,15 @@ static char vrt_hostname[255] = "";
 /*--------------------------------------------------------------------*/
 
 static void
-vrt_do_string(struct worker *w, int fd, const struct http *hp, int fld,
+vrt_do_string(const struct http *hp, int fld,
     const char *err, const char *p, va_list ap)
 {
 	char *b;
 
-	// AN(p);
 	AN(hp);
 	b = VRT_String(hp->ws, NULL, p, ap);
 	if (b == NULL || *b == '\0') {
-		WSL(w->vsl, SLT_LostHeader, fd, "%s", err);
+		VSLb(hp->vsl, SLT_LostHeader, "%s", err);
 	} else {
 		http_SetH(hp, fld, b);
 	}
@@ -68,9 +67,9 @@ VRT_l_##obj##_##hdr(const struct sess *sp, const char *p, ...)	\
 {								\
 	va_list ap;						\
 								\
+	(void)sp;						\
 	va_start(ap, p);					\
-	vrt_do_string(sp->wrk, sp->fd,				\
-	    http, fld, #obj "." #hdr, p, ap);			\
+	vrt_do_string(http, fld, #obj "." #hdr, p, ap);		\
 	va_end(ap);						\
 }								\
 								\
@@ -399,7 +398,7 @@ VRT_r_##which##_##fld(struct sess *sp)				\
 static void
 vrt_wsp_exp(const struct sess *sp, unsigned xid, const struct exp *e)
 {
-	WSP(sp, SLT_TTL, "%u VCL %.0f %.0f %.0f %.0f %.0f",
+	VSLb(sp->req->vsl, SLT_TTL, "%u VCL %.0f %.0f %.0f %.0f %.0f",
 	    xid, e->ttl - (sp->t_req - e->entered), e->grace, e->keep,
 	    sp->t_req, e->age + (sp->t_req - e->entered));
 }
diff --git a/bin/varnishd/storage/stevedore.c b/bin/varnishd/storage/stevedore.c
index dd517be..3a9f614 100644
--- a/bin/varnishd/storage/stevedore.c
+++ b/bin/varnishd/storage/stevedore.c
@@ -141,7 +141,7 @@ stv_pick_stevedore(struct vsl_log *vsl, const char **hint)
 			return (stv_transient);
 
 		/* Hint was not valid, nuke it */
-		WSL(vsl, SLT_Debug, -1, "Storage hint not usable");
+		VSLb(vsl, SLT_Debug, "Storage hint not usable");
 		*hint = NULL;
 	}
 	/* pick a stevedore and bump the head along */
diff --git a/lib/libvmod_std/vmod_std.c b/lib/libvmod_std/vmod_std.c
index e363b2d..5774cfb 100644
--- a/lib/libvmod_std/vmod_std.c
+++ b/lib/libvmod_std/vmod_std.c
@@ -152,7 +152,7 @@ vmod_log(struct sess *sp, const char *fmt, ...)
 	p = VRT_StringList(buf, sizeof buf, fmt, ap);
 	va_end(ap);
 	if (p != NULL)
-		WSP(sp, SLT_VCL_Log, "%s", buf);
+		VSLb(sp->req->vsl, SLT_VCL_Log, "%s", buf);
 }
 
 void



More information about the varnish-commit mailing list