Add a DSL() macro for diagnostic shmlogging and use it.

git-svn-id: http://www.varnish-cache.org/svn/trunk@2603 d4fa192b-c00b-0410-8231-f00ffab90ce4

bin/varnishd/cache.h

@@ -524,9 +524,17 @@ void VSL(enum shmlogtag tag, int id, const char *fmt, ...);
 void WSLR(struct worker *w, enum shmlogtag tag, int id, txt t);
 void WSL(struct worker *w, enum shmlogtag tag, int id, const char *fmt, ...);
 void WSL_Flush(struct worker *w, int overflow);
-#define WSP(sess, tag, fmt, ...) \
-	WSL((sess)->wrk, tag, (sess)->fd, fmt, __VA_ARGS__)
-#define WSPR(sess, tag, txt) \
+
+#define DSL(flag, tag, id, ...) 				\
+	do {							\
+		if (params->diag_bitmap & (flag))		\
+			VSL((tag), (id), __VA_ARGS__);		\
+	} while (0)
+
+#define WSP(sess, tag, ...) 					\
+	WSL((sess)->wrk, tag, (sess)->fd, __VA_ARGS__)
+
+#define WSPR(sess, tag, txt) 					\
 	WSLR((sess)->wrk, tag, (sess)->fd, txt)
 
 #define INCOMPL() do {							\

bin/varnishd/cache_acceptor_kqueue.c

@@ -83,8 +83,7 @@ vca_kq_sess(struct sess *sp, short arm)
 
 	CHECK_OBJ_NOTNULL(sp, SESS_MAGIC);
 	assert(sp->fd >= 0);
-	if (params->diag_bitmap & 4)
-		VSL(SLT_Debug, sp->fd, "KQ: EV_SET sp %p arm %x", sp, arm);
+	DSL(0x04, SLT_Debug, sp->fd, "KQ: EV_SET sp %p arm %x", sp, arm);
 	EV_SET(&ki[nki], sp->fd, EVFILT_READ, arm, 0, 0, sp);
 	if (++nki == NKEV) 
 		vca_kq_flush();
@@ -116,10 +115,9 @@ vca_kev(const struct kevent *kp)
 		return;
 	}
 	CAST_OBJ_NOTNULL(sp, kp->udata, SESS_MAGIC);
-	if (params->diag_bitmap & 0x4)
-		VSL(SLT_Debug, sp->id, "KQ: sp %p kev data %lu flags 0x%x%s",
-		    sp, (unsigned long)kp->data, kp->flags,
-		    (kp->flags & EV_EOF) ? " EOF" : "");
+	DSL(0x04, SLT_Debug, sp->id, "KQ: sp %p kev data %lu flags 0x%x%s",
+	    sp, (unsigned long)kp->data, kp->flags,
+	    (kp->flags & EV_EOF) ? " EOF" : "");
 
 	spassert(sp->id == kp->ident);
 	spassert(sp->fd == sp->id);

bin/varnishd/cache_expire.c

@@ -402,7 +402,7 @@ EXP_NukeOne(struct sess *sp)
 	o = oe->obj;
 
 	if (sp->handling == VCL_RET_DISCARD) {
-		VSL(SLT_ExpKill, 0, "%u LRU", o->xid);
+		WSL(sp->wrk, SLT_ExpKill, 0, "%u LRU", o->xid);
 		del_objexp(o);
 		HSH_Deref(o);
 		return (1);

bin/varnishd/cache_hash.c

@@ -278,8 +278,7 @@ hsh_rush(struct objhead *oh)
 		if (sp == NULL)
 			return;
 		VTAILQ_REMOVE(&oh->waitinglist, sp, list);
-		if (params->diag_bitmap & 0x20)
-			VSL(SLT_Debug, sp->id, "off waiting list");
+		DSL(0x20, SLT_Debug, sp->id, "off waiting list");
 		WRK_QueueSession(sp);
 	}
 }
@@ -365,9 +364,8 @@ HSH_Deref(struct object *o)
 	if (r != 0)
 		return;
 
-	if (params->diag_bitmap & 0x40)
-		VSL(SLT_Debug, 0, "Object %u workspace min free %u",
-		    o->xid, WS_Free(o->ws_o));
+	DSL(0x40, SLT_Debug, 0, "Object %u workspace min free %u",
+	    o->xid, WS_Free(o->ws_o));
 
 	if (o->vary != NULL)
 		free(o->vary);

bin/varnishd/cache_vrt_esi.c

@@ -619,7 +619,7 @@ VRT_ESI(struct sess *sp)
 	if (sp->cur_method != VCL_MET_FETCH) {
 		/* XXX: we should catch this at compile time */
 		WSP(sp, SLT_VCL_error,
-		    "esi can only be called from vcl_fetch", "");
+		    "esi can only be called from vcl_fetch");
 		return;
 	}
 

bin/varnishd/cache_ws.c

@@ -46,19 +46,12 @@
 #include "cli_priv.h"
 #include "cache.h"
 
-/* Enable this to get detailed logging of WS usage */
-#define WS_DEBUG(fmt, ...)					\
-	do {							\
-		if (params->diag_bitmap & 0x2)			\
-			VSL(SLT_Debug, 0, fmt, __VA_ARGS__);	\
-	} while (0)
-
 void
 WS_Assert(const struct ws *ws)
 {
 
 	CHECK_OBJ_NOTNULL(ws, WS_MAGIC);
-	WS_DEBUG("WS(%p = (%s, %p %u %u %u)",
+	DSL(0x02, SLT_Debug, 0, "WS(%p = (%s, %p %u %u %u)",
 	    ws, ws->id, ws->s, pdiff(ws->s, ws->f),
 	    ws->r == NULL ? 0 : pdiff(ws->f, ws->r),
 	    pdiff(ws->s, ws->e));
@@ -77,7 +70,8 @@ void
 WS_Init(struct ws *ws, const char *id, void *space, unsigned len)
 {
 
-	WS_DEBUG("WS_Init(%p, \"%s\", %p, %u)", ws, id, space, len);
+	DSL(0x02, SLT_Debug, 0,
+	    "WS_Init(%p, \"%s\", %p, %u)", ws, id, space, len);
 	assert(space != NULL);
 	memset(ws, 0, sizeof *ws);
 	ws->magic = WS_MAGIC;
@@ -93,7 +87,7 @@ WS_Reset(struct ws *ws, char *p)
 {
 
 	WS_Assert(ws);
-	WS_DEBUG("WS_Reset(%p, %p)", ws, p);
+	DSL(0x02, SLT_Debug, 0, "WS_Reset(%p, %p)", ws, p);
 	assert(ws->r == NULL);
 	if (p == NULL)
 		ws->f = ws->s;
@@ -117,7 +111,7 @@ WS_Alloc(struct ws *ws, unsigned bytes)
 	}
 	r = ws->f;
 	ws->f += bytes;
-	WS_DEBUG("WS_Alloc(%p, %u) = %p", ws, bytes, r);
+	DSL(0x02, SLT_Debug, 0, "WS_Alloc(%p, %u) = %p", ws, bytes, r);
 	return (r);
 }
 
@@ -131,7 +125,7 @@ WS_Dup(struct ws *ws, const char *s)
 	p = WS_Alloc(ws, l);
 	if (p != NULL)
 		memcpy(p, s, l);
-	WS_DEBUG("WS_Dup(%p, \"%s\") = %p", ws, s, p);
+	DSL(0x02, SLT_Debug, 0, "WS_Dup(%p, \"%s\") = %p", ws, s, p);
 	return (p);
 }
 
@@ -149,7 +143,7 @@ WS_Snapshot(struct ws *ws)
 
 	WS_Assert(ws);
 	assert(ws->r == NULL);
-	WS_DEBUG("WS_Snapshot(%p) = %p", ws, ws->f);
+	DSL(0x02, SLT_Debug, 0, "WS_Snapshot(%p) = %p", ws, ws->f);
 	return (ws->f);
 }
 
@@ -164,7 +158,7 @@ WS_Reserve(struct ws *ws, unsigned bytes)
 		b2 = ws->e - ws->f;
 	xxxassert(ws->f + b2 <= ws->e);
 	ws->r = ws->f + b2;
-	WS_DEBUG("WS_Reserve(%p, %u/%u) = %u",
+	DSL(0x02, SLT_Debug, 0, "WS_Reserve(%p, %u/%u) = %u",
 	    ws, b2, bytes, pdiff(ws->f, ws->r));
 	return (pdiff(ws->f, ws->r));
 }
@@ -173,7 +167,7 @@ void
 WS_Release(struct ws *ws, unsigned bytes)
 {
 	WS_Assert(ws);
-	WS_DEBUG("WS_Release(%p, %u)", ws, bytes);
+	DSL(0x02, SLT_Debug, 0, "WS_Release(%p, %u)", ws, bytes);
 	assert(ws->r != NULL);
 	assert(ws->f + bytes <= ws->r);
 	ws->f += bytes;
@@ -184,7 +178,7 @@ void
 WS_ReleaseP(struct ws *ws, char *ptr)
 {
 	WS_Assert(ws);
-	WS_DEBUG("WS_ReleaseP(%p, %p)", ws, ptr);
+	DSL(0x02, SLT_Debug, 0, "WS_ReleaseP(%p, %p)", ws, ptr);
 	assert(ws->r != NULL);
 	assert(ptr >= ws->f);
 	assert(ptr <= ws->r);