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: svn+ssh://projects.linpro.no/svn/varnish/trunk@2775 d4fa192b-c00b-0410-8231-f00ffab90ce4

diff --git a/varnish-cache/bin/varnishtest/vtc_log.c b/varnish-cache/bin/varnishtest/vtc_log.c
index e59a3f36763fc619d2a2683a7b80efb3c3e81497..44b85be06194cc2f088c1946371cebc92e5bc958 100644 (file)
--- a/varnish-cache/bin/varnishtest/vtc_log.c
+++ b/varnish-cache/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);
 }

diff --git a/varnish-cache/bin/varnishtest/vtc_varnish.c b/varnish-cache/bin/varnishtest/vtc_varnish.c
index 8557c34f322f8cd95cde44b6cac1742cf155b677..2075c83070c64af9bf29a558310691988f24aa2b 100644 (file)
--- a/varnish-cache/bin/varnishtest/vtc_varnish.c
+++ b/varnish-cache/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);
 }