A better solution than mutexes: give the thread that listens to

varnish debugging output a separate log handle.

(The point here is to maximize the amount of concurrency we can
simulate.  Down the road, the logging may become pre thread with
a final sorting pass to get all the messages correctly interleaved.)



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

bin/varnishtest/vtc_log.c

@@ -49,7 +49,6 @@ struct vtclog {
 #define VTCLOG_MAGIC	0x82731202
 	const char	*id;
 	struct vsb	*vsb;
-	pthread_mutex_t	mtx;
 };
 
 struct vtclog *
@@ -61,7 +60,6 @@ vtc_logopen(const char *id)
 	AN(vl);	
 	vl->id = id;
 	vl->vsb = vsb_newauto();
-	AZ(pthread_mutex_init(&vl->mtx, NULL));
 	return (vl);
 }
 
@@ -82,7 +80,6 @@ vtc_log(struct vtclog *vl, unsigned lvl, const char *fmt, ...)
 	assert(lvl < NLEAD);
 	if (lvl > vtc_verbosity)
 		return;
-	AZ(pthread_mutex_lock(&vl->mtx));
 	vsb_printf(vl->vsb, "%s %-4s ", lead[lvl], vl->id);
 	va_list ap;
 	va_start(ap, fmt);
@@ -93,7 +90,6 @@ vtc_log(struct vtclog *vl, unsigned lvl, const char *fmt, ...)
 	AZ(vsb_overflowed(vl->vsb));
 	(void)fputs(vsb_data(vl->vsb), stdout);
 	vsb_clear(vl->vsb);
-	AZ(pthread_mutex_unlock(&vl->mtx));
 	if (lvl == 0)
 		exit (1);
 }
@@ -112,7 +108,6 @@ vtc_dump(struct vtclog *vl, unsigned lvl, const char *pfx, const char *str)
 		return;
 	if (pfx == NULL)
 		pfx = "";
-	AZ(pthread_mutex_lock(&vl->mtx));
 	if (str == NULL) 
 		vsb_printf(vl->vsb, "%s %-4s %s(null)\n",
 		    lead[lvl], vl->id, pfx);
@@ -141,7 +136,6 @@ vtc_dump(struct vtclog *vl, unsigned lvl, const char *pfx, const char *str)
 	AZ(vsb_overflowed(vl->vsb));
 	(void)fputs(vsb_data(vl->vsb), stdout);
 	vsb_clear(vl->vsb);
-	AZ(pthread_mutex_unlock(&vl->mtx));
 	if (lvl == 0)
 		exit (1);
 }

bin/varnishtest/vtc_varnish.c

@@ -57,6 +57,7 @@ struct varnish {
 #define VARNISH_MAGIC		0x208cd8e3
 	char			*name;
 	struct vtclog		*vl;
+	struct vtclog		*vl1;
 	VTAILQ_ENTRY(varnish)	list;
 
 	const char		*args;
@@ -92,8 +93,8 @@ varnish_ask_cli(const struct varnish *v, const char *cmd, char **repl)
 	assert(i == 1);
 	i = cli_readres(v->cli_fd, &retval, &r, 1000);
 	assert(i == 0);
-	vtc_log(v->vl, 3, "CLI %u <%s>", retval, cmd);
 	vtc_dump(v->vl, 4, "CLI RX", r);
+	vtc_log(v->vl, 3, "CLI STATUS %u", retval);
 	if (repl != NULL)
 		*repl = r;
 	else
@@ -137,6 +138,8 @@ varnish_new(char *name)
 	v->name = name;
 	v->vl = vtc_logopen(name);
 	AN(v->vl);
+	v->vl1 = vtc_logopen(name);
+	AN(v->vl1);
 	if (*name != 'v') {
 		vtc_log(v->vl, 0, "Varnish name must start with 'v'");
 		exit (1);
@@ -167,7 +170,7 @@ varnish_thread(void *priv)
 		if (i <= 0)
 			break;
 		buf[i] = '\0';
-		vtc_dump(v->vl, 4, "debug", buf);
+		vtc_dump(v->vl1, 4, "debug", buf);
 	}
 	return (NULL);
 }