[master] 1ff8836 Make it possible to mark http stuff "non-fatal".
Poul-Henning Kamp
phk at varnish-cache.org
Tue Oct 25 11:45:10 CEST 2011
commit 1ff88369bf3690020975f2250ebad4ada39d1e0d
Author: Poul-Henning Kamp <phk at FreeBSD.org>
Date: Tue Oct 25 09:33:57 2011 +0000
Make it possible to mark http stuff "non-fatal".
The thread (s%d/c%d) still dies, but it does not mark this as
fatal with respect to the test as such.
This is useful where varnishd shuts the connection on a backend
prematurely, as part of the correct execution of a test.
Fix a undue recursion problem with asserts in the vtc_log code.
diff --git a/bin/varnishtest/vtc.h b/bin/varnishtest/vtc.h
index a1b6cbd..ee5308a 100644
--- a/bin/varnishtest/vtc.h
+++ b/bin/varnishtest/vtc.h
@@ -77,10 +77,10 @@ void cmd_server_genvcl(struct vsb *vsb);
void vtc_loginit(char *buf, unsigned buflen);
struct vtclog *vtc_logopen(const char *id);
void vtc_logclose(struct vtclog *vl);
-void vtc_log(struct vtclog *vl, unsigned lvl, const char *fmt, ...);
-void vtc_dump(struct vtclog *vl, unsigned lvl, const char *pfx,
+void vtc_log(struct vtclog *vl, int lvl, const char *fmt, ...);
+void vtc_dump(struct vtclog *vl, int lvl, const char *pfx,
const char *str, int len);
-void vtc_hexdump(struct vtclog *vl, unsigned lvl, const char *pfx,
+void vtc_hexdump(struct vtclog *vl, int lvl, const char *pfx,
const unsigned char *str, int len);
int exec_file(const char *fn, const char *script, const char *tmpdir,
diff --git a/bin/varnishtest/vtc_http.c b/bin/varnishtest/vtc_http.c
index 698ffb0..69485cc 100644
--- a/bin/varnishtest/vtc_http.c
+++ b/bin/varnishtest/vtc_http.c
@@ -67,6 +67,8 @@ struct http {
int gziplevel;
int gzipresidual;
+
+ int fatal;
};
#define ONLY_CLIENT(hp, av) \
@@ -137,7 +139,7 @@ http_write(const struct http *hp, int lvl, const char *pfx)
vtc_dump(hp->vl, lvl, pfx, VSB_data(hp->vsb), VSB_len(hp->vsb));
l = write(hp->fd, VSB_data(hp->vsb), VSB_len(hp->vsb));
if (l != VSB_len(hp->vsb))
- vtc_log(hp->vl, 0, "Write failed: (%d vs %d) %s",
+ vtc_log(hp->vl, hp->fatal, "Write failed: (%d vs %d) %s",
l, VSB_len(hp->vsb), strerror(errno));
}
@@ -339,10 +341,12 @@ http_rxchar(struct http *hp, int n, int eof)
pfd[0].revents = 0;
i = poll(pfd, 1, hp->timeout);
if (i == 0)
- vtc_log(hp->vl, 0, "HTTP rx timeout (fd:%d %u ms)",
+ vtc_log(hp->vl, hp->fatal,
+ "HTTP rx timeout (fd:%d %u ms)",
hp->fd, hp->timeout);
if (i < 0)
- vtc_log(hp->vl, 0, "HTTP rx failed (fd:%d poll: %s)",
+ vtc_log(hp->vl, hp->fatal,
+ "HTTP rx failed (fd:%d poll: %s)",
hp->fd, strerror(errno));
assert(i > 0);
assert(hp->prxbuf + n < hp->nrxbuf);
@@ -354,10 +358,12 @@ http_rxchar(struct http *hp, int n, int eof)
if (i == 0 && eof)
return (i);
if (i == 0)
- vtc_log(hp->vl, 0, "HTTP rx EOF (fd:%d read: %s)",
+ vtc_log(hp->vl, hp->fatal,
+ "HTTP rx EOF (fd:%d read: %s)",
hp->fd, strerror(errno));
if (i < 0)
- vtc_log(hp->vl, 0, "HTTP rx failed (fd:%d read: %s)",
+ vtc_log(hp->vl, hp->fatal,
+ "HTTP rx failed (fd:%d read: %s)",
hp->fd, strerror(errno));
hp->prxbuf += i;
hp->rxbuf[hp->prxbuf] = '\0';
@@ -381,7 +387,7 @@ http_rxchunk(struct http *hp)
bprintf(hp->chunklen, "%d", i);
if ((q == hp->rxbuf + l) ||
(*q != '\0' && !vct_islws(*q))) {
- vtc_log(hp->vl, 0, "chunked fail %02x @ %d",
+ vtc_log(hp->vl, hp->fatal, "chunked fail %02x @ %d",
*q, q - (hp->rxbuf + l));
}
assert(q != hp->rxbuf + l);
@@ -395,11 +401,11 @@ http_rxchunk(struct http *hp)
l = hp->prxbuf;
(void)http_rxchar(hp, 2, 0);
if(!vct_iscrlf(hp->rxbuf[l]))
- vtc_log(hp->vl, 0,
+ vtc_log(hp->vl, hp->fatal,
"Wrong chunk tail[0] = %02x",
hp->rxbuf[l] & 0xff);
if(!vct_iscrlf(hp->rxbuf[l + 1]))
- vtc_log(hp->vl, 0,
+ vtc_log(hp->vl, hp->fatal,
"Wrong chunk tail[1] = %02x",
hp->rxbuf[l + 1] & 0xff);
hp->prxbuf = l;
@@ -541,7 +547,8 @@ cmd_http_gunzip_body(CMD_ARGS)
memset(&vz, 0, sizeof vz);
if (hp->body[0] != (char)0x1f || hp->body[1] != (char)0x8b)
- vtc_log(hp->vl, 0, "Gunzip error: Body lacks gzip magics");
+ vtc_log(hp->vl, hp->fatal,
+ "Gunzip error: Body lacks gzip magics");
vz.next_in = TRUST_ME(hp->body);
vz.avail_in = hp->bodyl;
@@ -570,7 +577,8 @@ cmd_http_gunzip_body(CMD_ARGS)
(uintmax_t)vz.stop_bit,
(uintmax_t)vz.stop_bit >> 3, (uintmax_t)vz.stop_bit & 7);
if (i != Z_STREAM_END)
- vtc_log(hp->vl, 0, "Gunzip error = %d (%s) in:%jd out:%jd",
+ vtc_log(hp->vl, hp->fatal,
+ "Gunzip error = %d (%s) in:%jd out:%jd",
i, vz.msg, (intmax_t)vz.total_in, (intmax_t)vz.total_out);
assert(Z_OK == inflateEnd(&vz));
}
@@ -602,7 +610,8 @@ gzip_body(const struct http *hp, const char *txt, char **body, int *bodylen)
assert(Z_STREAM_END == deflate(&vz, Z_FINISH));
i = vz.stop_bit & 7;
if (hp->gzipresidual >= 0 && hp->gzipresidual != i)
- vtc_log(hp->vl, 0, "Wrong gzip residual got %d wanted %d",
+ vtc_log(hp->vl, hp->fatal,
+ "Wrong gzip residual got %d wanted %d",
i, hp->gzipresidual);
*bodylen = vz.total_out;
vtc_log(hp->vl, 4, "startbit = %ju %ju/%ju",
@@ -894,7 +903,7 @@ cmd_http_send(CMD_ARGS)
vtc_dump(hp->vl, 4, "send", av[1], -1);
i = write(hp->fd, av[1], strlen(av[1]));
if (i != strlen(av[1]))
- vtc_log(hp->vl, 0, "Write error in http_send(): %s",
+ vtc_log(hp->vl, hp->fatal, "Write error in http_send(): %s",
strerror(errno));
}
@@ -1036,9 +1045,9 @@ cmd_http_expect_close(CMD_ARGS)
fds[0].revents = 0;
i = poll(fds, 1, 1000);
if (i == 0)
- vtc_log(vl, 0, "Expected close: timeout");
+ vtc_log(vl, hp->fatal, "Expected close: timeout");
if (i != 1 || !(fds[0].revents & POLLIN))
- vtc_log(vl, 0,
+ vtc_log(vl, hp->fatal,
"Expected close: poll = %d, revents = 0x%x",
i, fds[0].revents);
i = read(hp->fd, &c, 1);
@@ -1046,7 +1055,7 @@ cmd_http_expect_close(CMD_ARGS)
break;
if (i == 1 && vct_islws(c))
continue;
- vtc_log(vl, 0,
+ vtc_log(vl, hp->fatal,
"Expecting close: read = %d, c = 0x%02x", i, c);
}
vtc_log(vl, 4, "fd=%d EOF, as expected", hp->fd);
@@ -1091,7 +1100,7 @@ cmd_http_accept(CMD_ARGS)
vtc_log(vl, 4, "Accepting");
hp->fd = accept(*hp->sfd, NULL, NULL);
if (hp->fd < 0)
- vtc_log(vl, 0, "Accepted failed: %s", strerror(errno));
+ vtc_log(vl, hp->fatal, "Accepted failed: %s", strerror(errno));
vtc_log(vl, 3, "Accepted socket fd is %d", hp->fd);
}
@@ -1120,6 +1129,26 @@ cmd_http_loop(CMD_ARGS)
}
/**********************************************************************
+ * Control fatality
+ */
+
+static void
+cmd_http_fatal(CMD_ARGS)
+{
+ struct http *hp;
+ CAST_OBJ_NOTNULL(hp, priv, HTTP_MAGIC);
+
+ AZ(av[1]);
+ if (!strcmp(av[0], "fatal"))
+ hp->fatal = 0;
+ else if (!strcmp(av[0], "non-fatal"))
+ hp->fatal = -1;
+ else {
+ vtc_log(vl, 0, "XXX: fatal %s", cmd->name);
+ }
+}
+
+/**********************************************************************
* Execute HTTP specifications
*/
@@ -1146,6 +1175,8 @@ static const struct cmds http_cmds[] = {
{ "close", cmd_http_close },
{ "accept", cmd_http_accept },
{ "loop", cmd_http_loop },
+ { "fatal", cmd_http_fatal },
+ { "non-fatal", cmd_http_fatal },
{ NULL, NULL }
};
diff --git a/bin/varnishtest/vtc_log.c b/bin/varnishtest/vtc_log.c
index d6d15c1..313d3ab 100644
--- a/bin/varnishtest/vtc_log.c
+++ b/bin/varnishtest/vtc_log.c
@@ -47,6 +47,7 @@ struct vtclog {
const char *id;
struct vsb *vsb;
pthread_mutex_t mtx;
+ int act;
};
static pthread_key_t log_key;
@@ -103,10 +104,12 @@ static const char * const lead[] = {
#define NLEAD (sizeof(lead)/sizeof(lead[0]))
static void
-vtc_log_emit(const struct vtclog *vl, unsigned lvl)
+vtc_log_emit(const struct vtclog *vl, int lvl)
{
int l;
+ if (lvl < 0)
+ lvl = 0;
if (vtc_stop && lvl == 0)
return;
l = VSB_len(vl->vsb);
@@ -121,16 +124,18 @@ vtc_log_emit(const struct vtclog *vl, unsigned lvl)
//lint -e{818}
void
-vtc_log(struct vtclog *vl, unsigned lvl, const char *fmt, ...)
+vtc_log(struct vtclog *vl, int lvl, const char *fmt, ...)
{
double tx;
CHECK_OBJ_NOTNULL(vl, VTCLOG_MAGIC);
tx = VTIM_mono() - t0;
AZ(pthread_mutex_lock(&vl->mtx));
+ vl->act = 1;
assert(lvl < NLEAD);
VSB_clear(vl->vsb);
- VSB_printf(vl->vsb, "%s %-4s %4.1f ", lead[lvl], vl->id, tx);
+ VSB_printf(vl->vsb, "%s %-4s %4.1f ",
+ lead[lvl < 0 ? 1: lvl], vl->id, tx);
va_list ap;
va_start(ap, fmt);
(void)VSB_vprintf(vl->vsb, fmt, ap);
@@ -141,12 +146,14 @@ vtc_log(struct vtclog *vl, unsigned lvl, const char *fmt, ...)
vtc_log_emit(vl, lvl);
VSB_clear(vl->vsb);
+ vl->act = 0;
AZ(pthread_mutex_unlock(&vl->mtx));
- if (lvl == 0) {
+ if (lvl > 0)
+ return;
+ if (lvl == 0)
vtc_error = 1;
- if (pthread_self() != vtc_thread)
- pthread_exit(NULL);
- }
+ if (pthread_self() != vtc_thread)
+ pthread_exit(NULL);
}
/**********************************************************************
@@ -155,7 +162,7 @@ vtc_log(struct vtclog *vl, unsigned lvl, const char *fmt, ...)
//lint -e{818}
void
-vtc_dump(struct vtclog *vl, unsigned lvl, const char *pfx, const char *str, int len)
+vtc_dump(struct vtclog *vl, int lvl, const char *pfx, const char *str, int len)
{
int nl = 1;
unsigned l;
@@ -164,7 +171,9 @@ vtc_dump(struct vtclog *vl, unsigned lvl, const char *pfx, const char *str, int
CHECK_OBJ_NOTNULL(vl, VTCLOG_MAGIC);
tx = VTIM_mono() - t0;
assert(lvl < NLEAD);
+ assert(lvl >= 0);
AZ(pthread_mutex_lock(&vl->mtx));
+ vl->act = 1;
VSB_clear(vl->vsb);
if (pfx == NULL)
pfx = "";
@@ -204,6 +213,7 @@ vtc_dump(struct vtclog *vl, unsigned lvl, const char *pfx, const char *str, int
vtc_log_emit(vl, lvl);
VSB_clear(vl->vsb);
+ vl->act = 0;
AZ(pthread_mutex_unlock(&vl->mtx));
if (lvl == 0) {
vtc_error = 1;
@@ -218,7 +228,7 @@ vtc_dump(struct vtclog *vl, unsigned lvl, const char *pfx, const char *str, int
//lint -e{818}
void
-vtc_hexdump(struct vtclog *vl, unsigned lvl, const char *pfx, const unsigned char *str, int len)
+vtc_hexdump(struct vtclog *vl, int lvl, const char *pfx, const unsigned char *str, int len)
{
int nl = 1;
unsigned l;
@@ -228,7 +238,9 @@ vtc_hexdump(struct vtclog *vl, unsigned lvl, const char *pfx, const unsigned cha
tx = VTIM_mono() - t0;
assert(len >= 0);
assert(lvl < NLEAD);
+ assert(lvl >= 0);
AZ(pthread_mutex_lock(&vl->mtx));
+ vl->act = 1;
VSB_clear(vl->vsb);
if (pfx == NULL)
pfx = "";
@@ -260,6 +272,7 @@ vtc_hexdump(struct vtclog *vl, unsigned lvl, const char *pfx, const unsigned cha
vtc_log_emit(vl, lvl);
VSB_clear(vl->vsb);
+ vl->act = 0;
AZ(pthread_mutex_unlock(&vl->mtx));
if (lvl == 0) {
vtc_error = 1;
@@ -279,7 +292,7 @@ vtc_log_VAS_Fail(const char *func, const char *file, int line,
(void)err;
(void)xxx;
vl = pthread_getspecific(log_key);
- if (vl == NULL) {
+ if (vl == NULL || vl->act) {
fprintf(stderr,
"Assert error in %s(), %s line %d:\n"
" Condition(%s) not true.\n",
More information about the varnish-commit
mailing list