[master] 389c050 Don't log logexpect error level from within the callback routine

[Martin Blix Grydeland]

commit 389c05031b7464a99305d2624f811054f3ef7b0f
Author: Martin Blix Grydeland <martin at varnish-software.com>
Date:   Tue Oct 28 15:14:26 2014 +0100

    Don't log logexpect error level from within the callback routine
    
    vtc_log does a pthread_exit when reporting an error condition. When
    this happened from within the API callback function for logexpect, the
    API internal data structures were left in an inconsistent state,
    causing asserts do be thrown during VSLQ_Delete().
    
    Signal the failed expect back from the callback function and do the
    vtc_log error level after the API function has returned.

diff --git a/bin/varnishtest/vtc_logexp.c b/bin/varnishtest/vtc_logexp.c
index 86de1ea..cbf11d6 100644
--- a/bin/varnishtest/vtc_logexp.c
+++ b/bin/varnishtest/vtc_logexp.c
@@ -183,7 +183,7 @@ logexp_dispatch(struct VSL_data *vsl, struct VSL_transaction * const pt[],
 	struct VSL_transaction *t;
 	int i;
 	int ok, skip;
-	int vxid, tag, type, len, lvl;
+	int vxid, tag, type, len;
 	const char *legend, *data;
 
 	(void)vsl;
@@ -228,22 +228,19 @@ logexp_dispatch(struct VSL_data *vsl, struct VSL_transaction * const pt[],
 				le->test->skip_max > le->skip_cnt))
 				skip = 1;
 
-			if (ok) {
-				lvl = 4;
+			if (ok)
 				legend = "ok";
-			} else if (skip) {
-				lvl = 4;
+			else if (skip)
 				legend = NULL;
-			} else {
-				lvl = 0;
+			else
 				legend = "err";
-			}
 			type = VSL_CLIENT(t->c->rec.ptr) ? 'c' :
 			    VSL_BACKEND(t->c->rec.ptr) ? 'b' : '-';
 
 			if (legend != NULL)
-				vtc_log(le->vl, lvl, "%3s| %10u %-15s %c %.*s",
-				    legend, vxid, VSL_tags[tag], type, len, data);
+				vtc_log(le->vl, 4, "%3s| %10u %-15s %c %.*s",
+				    legend, vxid, VSL_tags[tag], type, len,
+				    data);
 
 			if (ok) {
 				le->vxid_last = vxid;
@@ -253,9 +250,12 @@ logexp_dispatch(struct VSL_data *vsl, struct VSL_transaction * const pt[],
 				if (le->test == NULL)
 					/* End of test script */
 					return (1);
-			}
-			if (skip)
+			} else if (skip)
 				le->skip_cnt++;
+			else {
+				/* Signal fail */
+				return (2);
+			}
 		}
 	}
 
@@ -281,9 +281,11 @@ logexp_thread(void *priv)
 	logexp_next(le);
 	while (le->test) {
 		i = VSLQ_Dispatch(le->vslq, logexp_dispatch, le);
-		if (i < 0)
-			vtc_log(le->vl, 0, "dispatch: %d", i);
-		if (i == 0 && le->test)
+		if (i == 2)
+			vtc_log(le->vl, 0, "bad| expectation failed");
+		else if (i < 0)
+			vtc_log(le->vl, 0, "bad| dispatch failed (%d)", i);
+		else if (i == 0 && le->test)
 			VTIM_sleep(0.01);
 	}
 	vtc_log(le->vl, 4, "end|");